aya-log: make logging zero-copy #1294
Conversation
mergify
bot
added
aya-bpf
✅ Deploy Preview for aya-rs-docs ready!Built without sensitive environment variables
To edit notification comments on pull requests, go to your Netlify project configuration. |
tamird
force-pushed
the
log-zero-copy
branch
2 times, most recently
from
68892da to
20e3328
Compare
There was a problem hiding this comment.
Neat!
Reviewed 1 of 1 files at r1, 2 of 2 files at r2, 5 of 5 files at r3, all commit messages.
Reviewable status: all files reviewed, 3 unresolved discussions (waiting on @alessandrod and @vadorovsky)
aya-log-ebpf-macros/src/expand.rs line 166 at r3 (raw file):
use ::aya_log_ebpf::macro_support::{Header, Field, Argument, AYA_LOGS}; let #num_args = match u32::try_from(#len) {
You know len statically in the macro, just check there and make it a u32 ident?
aya-log-ebpf-macros/src/expand.rs line 180 at r3 (raw file):
#( let #tmp = #values;
I feel like the more Tamir way to write this would have been the following. Any reason you prefer the splatting and then tmp?
#(
let #idents = {
let (#kind, #value) = #values.as_argument();
Field::new(kind, value)?
};
)*aya-log-ebpf-macros/src/expand.rs line 185 at r3 (raw file):
)* let mut #size = 0;
It's rather amazing that this works and always verifies. I wonder how much of this is LLVM evaluating into constants ahead of time and how much is symbolic execution. I wonder if there's a size cutoff for a large number of arguments where the behavior changes. If you have the compiled bytecode of the log integration test ebpf program handy, I'd be curious to look at it. Did you have any trouble with the verifier on this?
ebpf/aya-log-ebpf/src/lib.rs line 17 at r3 (raw file):
}; const LOG_BUF_CAPACITY: LogValueLength = 8192;
I think this constant is sort of meaningless now. The maximum log size ends up being the maximum message size for the ringbuffer given the capacity it's configured with (which can be overridden prior to loading). I wonder how bad the error message is when you hit it -- I suspect it'll just be a verifier failure.
There was a problem hiding this comment.
Reviewable status: 2 of 7 files reviewed, 1 unresolved discussion (waiting on @ajwerner, @alessandrod, and @vadorovsky)
aya-log-ebpf-macros/src/expand.rs line 166 at r3 (raw file):
Previously, ajwerner wrote…
You know len statically in the macro, just check there and make it a u32 ident?
Yeah, okay - done.
aya-log-ebpf-macros/src/expand.rs line 180 at r3 (raw file):
Previously, ajwerner wrote…
I feel like the more Tamir way to write this would have been the following. Any reason you prefer the splatting and then tmp?
#( let #idents = { let (#kind, #value) = #values.as_argument(); Field::new(kind, value)? }; )*
The return of Argument::as_argument is borrowed from self:
fn as_argument(&self) -> (ArgumentKind, impl AsRef<[u8]>);
(there's a lifetime hidden in that impl AsRef<[u8]>)
aya-log-ebpf-macros/src/expand.rs line 185 at r3 (raw file):
Previously, ajwerner wrote…
It's rather amazing that this works and always verifies. I wonder how much of this is LLVM evaluating into constants ahead of time and how much is symbolic execution. I wonder if there's a size cutoff for a large number of arguments where the behavior changes. If you have the compiled bytecode of the log integration test ebpf program handy, I'd be curious to look at it. Did you have any trouble with the verifier on this?
I had some trouble when I tried to do fancier things like chaining iterators rather than the closure passing you see in the current version.
Yep, here it is: https://drive.google.com/file/d/1fHIO5Xq7tvGaDrcvvx_Gde7nwEBGCQz8/view?usp=sharing
ebpf/aya-log-ebpf/src/lib.rs line 17 at r3 (raw file):
Previously, ajwerner wrote…
I think this constant is sort of meaningless now. The maximum log size ends up being the maximum message size for the ringbuffer given the capacity it's configured with (which can be overridden prior to loading). I wonder how bad the error message is when you hit it -- I suspect it'll just be a verifier failure.
Yeah, this constant is utterly meaningless, I'll remove it.
As for the size being configurable: of course you're right and it is, but we don't currently expose an API to do so specifically for aya-log. You could obviously reach into the program and configure it, though.
Regarding the verifier failure, I'm not sure - I would think that if you tried to log something too big you'd hit one of the ?s in the macro expansion and just silently not log anything. Don't you think?
There was a problem hiding this comment.
Reviewable status: 2 of 7 files reviewed, all discussions resolved (waiting on @alessandrod and @vadorovsky)
aya-log-ebpf-macros/src/expand.rs line 180 at r3 (raw file):
Previously, tamird (Tamir Duberstein) wrote…
The return of
Argument::as_argumentis borrowed fromself:fn as_argument(&self) -> (ArgumentKind, impl AsRef<[u8]>);(there's a lifetime hidden in that
impl AsRef<[u8]>)
Ah, yes
aya-log-ebpf-macros/src/expand.rs line 185 at r3 (raw file):
Previously, tamird (Tamir Duberstein) wrote…
I had some trouble when I tried to do fancier things like chaining iterators rather than the closure passing you see in the current version.
Yep, here it is: https://drive.google.com/file/d/1fHIO5Xq7tvGaDrcvvx_Gde7nwEBGCQz8/view?usp=sharing
It's incredible. Compilers are so dope. It literally does boil down to completely eliminating the size computation into static values in the assembly and inline instructions to copy data into the buffer.
For the first call (commentary mine):
1: 18 01 00 00 00 00 00 00 00 00 00 00 00 00 00 00 r1 = 0x0 ll // map pointer to be filled in
3: b7 02 00 00 54 00 00 00 r2 = 0x54 // #size
4: b7 03 00 00 00 00 00 00 r3 = 0x0 // flags
5: 85 00 00 00 83 00 00 00 call 0x83 // bpf_ringbuf_reserve
; #[inline]
6: 15 00 a4 00 00 00 00 00 if r0 == 0x0 goto +0xa4 <test_log+0x558> // failure check
// fill in the buffer with exact offset
https://gist.github.com/ajwerner/3b7cca9336c7f913d2982ae7e9a38ebd
There was a problem hiding this comment.
Reviewable status: 2 of 7 files reviewed, all discussions resolved (waiting on @ajwerner, @alessandrod, and @vadorovsky)
aya-log-ebpf-macros/src/expand.rs line 185 at r3 (raw file):
Previously, ajwerner wrote…
It's incredible. Compilers are so dope. It literally does boil down to completely eliminating the size computation into static values in the assembly and inline instructions to copy data into the buffer.
For the first call (commentary mine):
1: 18 01 00 00 00 00 00 00 00 00 00 00 00 00 00 00 r1 = 0x0 ll // map pointer to be filled in 3: b7 02 00 00 54 00 00 00 r2 = 0x54 // #size 4: b7 03 00 00 00 00 00 00 r3 = 0x0 // flags 5: 85 00 00 00 83 00 00 00 call 0x83 // bpf_ringbuf_reserve ; #[inline] 6: 15 00 a4 00 00 00 00 00 if r0 == 0x0 goto +0xa4 <test_log+0x558> // failure check // fill in the buffer with exact offsethttps://gist.github.com/ajwerner/3b7cca9336c7f913d2982ae7e9a38ebd
This got me wondering what would happen if I added a test that tried to log a value whose size was not a compile-time constant.
I wrote this and the result is verifier failure:
2720: (b7) r1 = 1024 ; R1=1024
; let buf = if len < buf.len() {
2721: (2d) if r1 > r7 goto pc+1 2723: R0=map_value(off=0,ks=4,vs=1032,imm=0) R1=1024 R6=map_value(off=0,ks=4,vs=1032,imm=0) R7=scalar(umax=1023,var_off=(0x0; 0x3ff)) R8=115 R9=19 R10=fp0 fp-8=mmmm????
; info!(&ctx, "variable length buffer: {:x}", buf);
2723: (bf) r2 = r7 ; R2_w=scalar(id=29,umax=1023,var_off=(0x0; 0x3ff)) R7=scalar(id=29,umax=1023,var_off=(0x0; 0x3ff))
2724: (07) r2 += 99 ; R2_w=scalar(umin=99,umax=1122,var_off=(0x0; 0x7ff))
2725: (b7) r8 = 0 ; R8_w=0
; fun(ringbuf, size, flags)
2726: (18) r1 = 0xffff5f3d823cc200 ; R1_w=map_ptr(off=0,ks=0,vs=0,imm=0)
2728: (b7) r3 = 0 ; R3_w=0
2729: (85) call bpf_ringbuf_reserve#131
R2 is not a known constant'
maybe this is the reason we didn't implement support for DSTs when we first wrote the ring buffer abstraction?
There was a problem hiding this comment.
Reviewable status: 2 of 10 files reviewed, 1 unresolved discussion (waiting on @alessandrod and @vadorovsky)
aya-log-ebpf-macros/src/expand.rs line 185 at r3 (raw file):
Previously, tamird (Tamir Duberstein) wrote…
This got me wondering what would happen if I added a test that tried to log a value whose size was not a compile-time constant.
I wrote this and the result is verifier failure:
2720: (b7) r1 = 1024 ; R1=1024 ; let buf = if len < buf.len() { 2721: (2d) if r1 > r7 goto pc+1 2723: R0=map_value(off=0,ks=4,vs=1032,imm=0) R1=1024 R6=map_value(off=0,ks=4,vs=1032,imm=0) R7=scalar(umax=1023,var_off=(0x0; 0x3ff)) R8=115 R9=19 R10=fp0 fp-8=mmmm???? ; info!(&ctx, "variable length buffer: {:x}", buf); 2723: (bf) r2 = r7 ; R2_w=scalar(id=29,umax=1023,var_off=(0x0; 0x3ff)) R7=scalar(id=29,umax=1023,var_off=(0x0; 0x3ff)) 2724: (07) r2 += 99 ; R2_w=scalar(umin=99,umax=1122,var_off=(0x0; 0x7ff)) 2725: (b7) r8 = 0 ; R8_w=0 ; fun(ringbuf, size, flags) 2726: (18) r1 = 0xffff5f3d823cc200 ; R1_w=map_ptr(off=0,ks=0,vs=0,imm=0) 2728: (b7) r3 = 0 ; R3_w=0 2729: (85) call bpf_ringbuf_reserve#131 R2 is not a known constant'maybe this is the reason we didn't implement support for DSTs when we first wrote the ring buffer abstraction?
Correct. For writing to ringbufs you need the offsets and the buffer capacity to be a statically known size. If you want the underlying allocation to be variable size, you can get access to a statically sized sub-array with bpf_ringbuf_reserve_dynptr and then bpf_dynptr_data but that's not available until 5.19. If you want to do a dynamically sized write, you have to use bpf_dynptr_write.
test/integration-ebpf/src/log.rs line 113 at r10 (raw file):
&buf[..] }; info!(&ctx, "variable length buffer: {:x}", buf);
comment that this doesn't work but does verify?
There was a problem hiding this comment.
Great work! Just a few nits.
Reviewed 1 of 1 files at r1, 2 of 2 files at r2, 5 of 5 files at r3, 2 of 5 files at r7.
Reviewable status: 2 of 10 files reviewed, 4 unresolved discussions (waiting on @ajwerner, @alessandrod, and @tamird)
test/integration-ebpf/src/log.rs line 112 at r10 (raw file):
} else { &buf[..] };
Or perhaps even &buf[..len] if we can guarantee that len never exceeds the buffer length.
Suggestion:
let buf = &buf[..cmp::min(len, buf.len())];aya-log-ebpf-macros/src/expand.rs line 202 at r10 (raw file):
let mut #op = |slice: &[u8]| { let #buf = #buf.get_mut(#size..)?; let #buf = #buf.get_mut(..slice.len())?;
I think that getting a slice with the full range should work?
Suggestion:
let #buf = #buf.get_mut(#size..slice.len())?;aya-log/src/lib.rs line 797 at r10 (raw file):
let mut op = |slice: &[u8]| { let buf = buf.get_mut(size..)?; let buf = buf.get_mut(..slice.len())?;
I think that getting a slice with the full range should work?
Suggestion:
let buf = buf.get_mut(size..slice.len())?;
There was a problem hiding this comment.
Reviewable status: 2 of 10 files reviewed, 4 unresolved discussions (waiting on @ajwerner, @alessandrod, and @vadorovsky)
aya-log/src/lib.rs line 797 at r10 (raw file):
Previously, vadorovsky (Michal Rostecki) wrote…
I think that getting a slice with the full range should work?
This is not equivalent. The equivalent would be let buf = buf.get_mut(size..size+slice.len())?; but then my overflow spidey sense starts tingling and I think it's not worth it.
aya-log-ebpf-macros/src/expand.rs line 185 at r3 (raw file):
Previously, ajwerner wrote…
Correct. For writing to ringbufs you need the offsets and the buffer capacity to be a statically known size. If you want the underlying allocation to be variable size, you can get access to a statically sized sub-array with bpf_ringbuf_reserve_dynptr and then bpf_dynptr_data but that's not available until 5.19. If you want to do a dynamically sized write, you have to use
bpf_dynptr_write.
Ah, I see. I hadn't appreciated that. I think I will rework this PR by just allocating a fixed size buffer from the RB (the old 8k constant) and write to it in the manner previously used to write to the scratch buffer. Most of the refactoring in this PR can be shelved -- calculating the size in advance of writing doesn't really buy us much.
aya-log-ebpf-macros/src/expand.rs line 202 at r10 (raw file):
Previously, vadorovsky (Michal Rostecki) wrote…
I think that getting a slice with the full range should work?
Same as the other.
test/integration-ebpf/src/log.rs line 113 at r10 (raw file):
Previously, ajwerner wrote…
comment that this doesn't work but does verify?
Well, it does not verify!
There was a problem hiding this comment.
Reviewable status: 2 of 10 files reviewed, 4 unresolved discussions (waiting on @alessandrod, @tamird, and @vadorovsky)
aya-log-ebpf-macros/src/expand.rs line 185 at r3 (raw file):
Previously, tamird (Tamir Duberstein) wrote…
Ah, I see. I hadn't appreciated that. I think I will rework this PR by just allocating a fixed size buffer from the RB (the old 8k constant) and write to it in the manner previously used to write to the scratch buffer. Most of the refactoring in this PR can be shelved -- calculating the size in advance of writing doesn't really buy us much.
Well, I don't know, I think it does buy you something: you reserve what you need. Most log messages will not be 8k. if you reserve too much, then the number of logs you can have in the buffer unprocessed is much smaller. In fact it'll be exactly 15 messages, no (128/8 - 1 for the headers)? You can't shrink a reservation after you reserve it. Like I'd rather an extra copy than a maximum capacity of 15 messages.
So yeah, another approach is to well, no zero copy and go back to having a buffer. One thing I've learned is that per cpu arrays aren't sound in preemptible bpf programs in the general case. I think later kernels can preempt xdp and then also there are the sleepable k/u probes.
In conclusion: I do think this move towards being zero-copy is a good idea and I think how you had it before where variable size things do not work was ~fine. What'd be great is a way to enforce that these sizes can be const computed for all types that are loggable and maybe also we need to seal what you can log?
There was a problem hiding this comment.
Reviewable status: 2 of 10 files reviewed, 4 unresolved discussions (waiting on @ajwerner, @alessandrod, and @vadorovsky)
aya-log-ebpf-macros/src/expand.rs line 185 at r3 (raw file):
What'd be great is a way to enforce that these sizes can be const computed for all types that are loggable and maybe also we need to seal what you can log?
Yeah, these are both good things to call out. I'll definitely adding the seal and then I'll look into enforcing compile-time size calculation. The latter might be hard because trait functions cannot be declared const. Certainly the north star here is that we should be able to remove the new ringbuf methods I added since true DSTs cannot be used.
This change is