Add set_print, to send libbpf output to a callback #137

benfogle · 2021-10-29T19:28:56Z

I want to be able to send output from libbpf-rs to the log crate and filter it by level, along with all the other chatter my application produces. Right now the best I can do is send it to stderr. This PR adds set_print, which allows a user-defined callback to receive libbpf output.

mimullin-bbry · 2021-10-31T04:56:34Z

I was just thinking that something like this was needed. :)

anakryiko · 2021-11-02T04:14:46Z

libbpf-rs/src/print.rs

+pub fn set_print(func: PrintCallback) {
+    let cb = unsafe { std::mem::transmute::<PrintCallback, *mut ()>(func) };
+    PRINT_CB.store(cb, Ordering::Relaxed);
+    unsafe { libbpf_sys::libbpf_set_print(Some(outer_print_cb)) };


libbpf_set_print returns the previous instance of print callback. It's quite important and useful when someone wants to temporarily replace print callback and restore the previous one. Can the same pattern be support in Rust?

I can rework this to include that. I was a little unsure about how to handle return values. The return from libbpf_set_print would be a nullable, unsafe function pointer, so at best it could be a token to restore things later. Since in my implementation, the real callback is a static function, the libbpf_set_print's return value alone wouldn't be sufficient to restore the print callback in a way the user expects.

Would something like a resource guard be acceptable here, or do you think there is a real need to expose the return value?

{ let _lock = libbpf_rs::set_print_temporary(callback); ... } // Original callback restored here

Resource guard seems like an overkill. We can make set_print() not return anything in libbpf-rs. Alternatively you can return PrintCallback and just keep track of current callback on purely Rust side. It might be a bit fragile if someone is calling into libbpf_set_print() through FFI, but that should be extremely rare (an we can say unsupported) case.

All right, that should be updated.

insearchoflosttime

Thanks for working on this!!

libbpf-rs/src/print.rs

insearchoflosttime · 2021-11-03T22:47:40Z

libbpf-rs/src/print.rs

-    // pointer.
-    let cb = PRINT_CB.load(Ordering::Relaxed);
-    let cb = unsafe { std::mem::transmute::<*const (), PrintCallback>(cb) };
+    let cb = from_ptr(PRINT_CB.load(Ordering::Relaxed));
    match unsafe { vsprintf::vsprintf(fmtstr, va_list) } {


Some callbacks may filter by log level (eg benchmark tests may discard all debug logs). In those cases, it'd be great to just return early here instead of calling vsprintf and calling into the cb. Maybe in the set_print API, we could also take in the level to filter by as another parameter, and then in this function here, check whether the message should be discarded or forwarded to the cb based off that filter. What are your thoughts on this?

That's a good point. Rather than complicate the API, I changed the paramter from &str to &dyn Display. This way it will be lazily evaluated only when the user needs it.

benfogle · 2021-11-04T12:55:13Z

I rebased off master to resolve some of the test errors I was seeing.

libbpf-rs/src/print.rs

insearchoflosttime · 2021-11-04T18:05:19Z

libbpf-rs/src/print.rs

@@ -23,16 +24,31 @@ impl From<libbpf_sys::libbpf_print_level> for PrintLevel {
    }
 }

-pub type PrintCallback = fn(PrintLevel, &str);
+pub type PrintCallback = fn(PrintLevel, &dyn fmt::Display);


I think the simplest solution is expanding the set_print API to take in the log level to filter by a parameter, and keeping this print callback as a fn(PrintLevel, &str). One additional benefit of this is that users also then no longer have to do an if check themselves in their callback function to filter logs by the log level they want.

Other than this, your commits LGTM!

I'm not going to push back very hard on this, because it's all minor details, but I still don't know about adding a filter parameter:

Should the parameter be a minimum level to show or a maximum level to hide?

Inclusive or exclusive?

Depending on the previous answers, we'll need to introduce a PrintLevel::All or PrintLevel::None that does not exist in libbpf.

I really don't think that requiring the user to write an if-statement is much of a burden, especially because I'm of the opinion that the most common use will be to pass this on to log or syslog or something, which means users will need a match to convert PrintLevel to log::Level, etc. anyway..

Reflecting on this, maybe the real solution is to make take a dyn Fn(...) + 'static so that we can pass closures as well as function pointers. That would be a much nicer interface, and there's really no reason I couldn't have done it that way.

I don't think we need to add PrintLevel::All or PrintLevel::None. The way I envision it working is hierarchically - if the filter is set to LIBBPF_WARN, then only LIBBPF_WARN messages should go through (LIBBPF_INFO and LIBBPF_DEBUG messages should be discarded). If the filter is set to LIBBPF_INFO, then LIBBPF_WARN and LIBBPF_INFO go through while LIBBPF_DEBUG messages are discarded. And if the filter is set to LIBBPF_DEBUG messages, then all messages go through.

How should this work with restoring a previous callback?

We could add a getter function that will return to the user the current callback and print level, and correspondingly set_print would return back nothing. If the user has a particular callback + print level they want to restore in the future, then the user is responsible for getting and keeping that around, before the user replaces set_print with a new callback + print level. What are your thoughts on this?

I can implement that. We'll still need a PrintLevel::None if we want to avoid the vsprintf penalty when turning off log messages completely. Or the callback can be an Option.

anakryiko · 2021-11-08T19:42:55Z

@benfogle, for the PrintLevel::None you mean if the users doesn't want to get any logs at all, right? I think Option is probably best, it's same as passing NULL to libbpf C api.

benfogle · 2021-11-09T14:53:49Z

Alright, another try. Changes made:

set_print takes an Option<(level, callback)> for a parameter.
get_print returns current callback as Option<(level, callback)>.
PrintCallback takes a String. (We don't do anything with the string afterwards so we might as well let the user take ownership of it.)
Examples in the docstrings.

insearchoflosttime

Thank you for these changes, these look great. Have a few small questions asked inline.

libbpf-rs/Cargo.toml

libbpf-rs/src/print.rs

anakryiko

Same as for the other PR, please squash, provide good commit description and add your Signed-off-by:. Thanks!

anakryiko · 2021-11-04T17:38:35Z

libbpf-rs/src/object.rs

@@ -29,30 +29,14 @@ impl ObjectBuilder {
    }

    /// Option to print debug output to stderr.
+    ///
+    /// Note: This function interacts poorly with [`set_print`].


let's be more specific than "interacts poorly"? Just specify that this will reset whatever callback was set with set_print().

anakryiko · 2021-11-11T00:42:02Z

libbpf-rs/src/print.rs

+            func(level, msg);
+        }
+    }
+    1 // return value is ignored by libbpf


it is ignored, but conventionally 0 means success, so might as well return 0

anakryiko · 2021-11-11T00:44:58Z

libbpf-rs/src/print.rs

+/// // do things quietly
+/// set_print(prev);
+/// ```
+pub fn get_print() -> Option<(PrintLevel, PrintCallback)> {


if we have PrintLevel and PrintCallback in tuples together everywhere, we might as well return it from set_print. Nothing wrong with keeping get_print as well.

benfogle · 2021-11-12T14:11:35Z

Comments should be addressed. Let me know if the commit message looks good and if the signed-off-by line has all the correct info for this PR.

insearchoflosttime · 2021-11-13T03:06:15Z

This LGTM. Thanks for making these changes.

One small nit: your signed-off by line should be

Signed-off-by: Ben Fogle

not Andrii's info :) (and for more information on "signed-off-by", https://www.kernel.org/doc/html/latest/process/submitting-patches.html might be helpful). This is something we will make more clear in the contributors' guidelines.

Would you mind amending your signed-off-by?

This commit exposes libbpf_set_print to direct libbpf output to a user-defined callback. Signed-off-by: Benjamin Fogle <benfogle@gmail.com>

benfogle · 2021-11-14T16:51:36Z

hahahaha. It's been a long week, I guess. Fixed in both PRs.

anakryiko reviewed Nov 2, 2021

View reviewed changes

insearchoflosttime reviewed Nov 3, 2021

View reviewed changes

benfogle force-pushed the set-print-func branch from ddccd2b to e32ccb7 Compare November 4, 2021 12:52

insearchoflosttime reviewed Nov 4, 2021

View reviewed changes

insearchoflosttime reviewed Nov 10, 2021

View reviewed changes

libbpf-rs/Cargo.toml Show resolved Hide resolved

libbpf-rs/src/print.rs Show resolved Hide resolved

anakryiko reviewed Nov 11, 2021

View reviewed changes

benfogle force-pushed the set-print-func branch 2 times, most recently from d04ee13 to a6b1205 Compare November 12, 2021 14:09

insearchoflosttime approved these changes Nov 13, 2021

View reviewed changes

libbpf-rs: Add set_print/get_print, to send libbpf output to a callback

6ffca59

This commit exposes libbpf_set_print to direct libbpf output to a user-defined callback. Signed-off-by: Benjamin Fogle <benfogle@gmail.com>

benfogle force-pushed the set-print-func branch from a6b1205 to 6ffca59 Compare November 14, 2021 16:50

insearchoflosttime merged commit 283c0e5 into libbpf:master Nov 15, 2021

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

Add set_print, to send libbpf output to a callback #137

Add set_print, to send libbpf output to a callback #137

benfogle commented Oct 29, 2021

mimullin-bbry commented Oct 31, 2021

anakryiko Nov 2, 2021

benfogle Nov 2, 2021

anakryiko Nov 2, 2021

benfogle Nov 2, 2021

insearchoflosttime left a comment

insearchoflosttime Nov 3, 2021

benfogle Nov 4, 2021

benfogle commented Nov 4, 2021

insearchoflosttime Nov 4, 2021

benfogle Nov 5, 2021

benfogle Nov 5, 2021

insearchoflosttime Nov 5, 2021

benfogle Nov 5, 2021

insearchoflosttime Nov 8, 2021

benfogle Nov 8, 2021

anakryiko commented Nov 8, 2021

benfogle commented Nov 9, 2021

insearchoflosttime left a comment

anakryiko left a comment

anakryiko Nov 4, 2021

anakryiko Nov 11, 2021

anakryiko Nov 11, 2021

benfogle commented Nov 12, 2021

insearchoflosttime commented Nov 13, 2021 •

edited

Loading

benfogle commented Nov 14, 2021

Add set_print, to send libbpf output to a callback #137

Add set_print, to send libbpf output to a callback #137

Conversation

benfogle commented Oct 29, 2021

mimullin-bbry commented Oct 31, 2021

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

insearchoflosttime left a comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

benfogle commented Nov 4, 2021

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

anakryiko commented Nov 8, 2021

benfogle commented Nov 9, 2021

insearchoflosttime left a comment

Choose a reason for hiding this comment

anakryiko left a comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

benfogle commented Nov 12, 2021

insearchoflosttime commented Nov 13, 2021 • edited Loading

benfogle commented Nov 14, 2021

insearchoflosttime commented Nov 13, 2021 •

edited

Loading