On Fri, Mar 17, 2023 at 4:02 PM Daniel Borkmann <daniel@xxxxxxxxxxxxx> wrote: > > On 3/17/23 11:03 PM, Andrii Nakryiko wrote: > > Currently, if user-supplied log buffer to collect BPF verifier log turns > > out to be too small to contain full log, bpf() syscall return -ENOSPC, > > fails BPF program verification/load, but preserves first N-1 bytes of > > verifier log (where N is the size of user-supplied buffer). > > > > This is problematic in a bunch of common scenarios, especially when > > working with real-world BPF programs that tend to be pretty complex as > > far as verification goes and require big log buffers. Typically, it's > > when debugging tricky cases at log level 2 (verbose). Also, when BPF program > > is successfully validated, log level 2 is the only way to actually see > > verifier state progression and all the important details. > > > > Even with log level 1, it's possible to get -ENOSPC even if the final > > verifier log fits in log buffer, if there is a code path that's deep > > enough to fill up entire log, even if normally it would be reset later > > on (there is a logic to chop off successfully validated portions of BPF > > verifier log). > > > > In short, it's not always possible to pre-size log buffer. Also, in > > practice, the end of the log most often is way more important than the > > beginning. > > > > This patch switches BPF verifier log behavior to effectively behave as > > rotating log. That is, if user-supplied log buffer turns out to be too > > short, instead of failing with -ENOSPC, verifier will keep overwriting > > previously written log, effectively treating user's log buffer as a ring > > buffer. > > > > Importantly, though, to preserve good user experience and not require > > every user-space application to adopt to this new behavior, before > > exiting to user-space verifier will rotate log (in place) to make it > > start at the very beginning of user buffer as a continuous > > zero-terminated string. The contents will be a chopped off N-1 last > > bytes of full verifier log, of course. > > > > Given beginning of log is sometimes important as well, we add > > BPF_LOG_FIXED (which equals 8) flag to force old behavior, which allows > > tools like veristat to request first part of verifier log, if necessary. > > > > On the implementation side, conceptually, it's all simple. We maintain > > 64-bit logical start and end positions. If we need to truncate the log, > > start position will be adjusted accordingly to lag end position by > > N bytes. We then use those logical positions to calculate their matching > > actual positions in user buffer and handle wrap around the end of the > > buffer properly. Finally, right before returning from bpf_check(), we > > rotate user log buffer contents in-place as necessary, to make log > > contents contiguous. See comments in relevant functions for details. > > > > Signed-off-by: Andrii Nakryiko <andrii@xxxxxxxxxx> > > Did you check behavior with other loaders if changing default works ok > for them, e.g. their behavior/buffer around ENOSPC handling for growing? > > The go loader library did some parsing around the log [0], adding Lorenz > and Timo for Cc for checking. I didn't, no. Thanks for pinging Lorenz and Timo. Libbpf by default uses 16MB right now, I didn't touch that part yet, but it might be good to reduce this size if the kernel supports this new behavior. Go library seems to be using 64KB, which probably would be adequate for a lot of cases, but yeah, maybe Go library would like to use slightly bigger default if rotating log behavior is supported by kernel? Alternative would be to make this rotating behavior opt-in, but that would require active actions by multiple libraries and applications to actively detect support. Given the rotating behavior seems like a good default behavior I wish we had from the very beginning, I went for making it default. Let's see what Lorenz and Timo think. Adding also aya-rs main contributors (Allesandro and Dave). Seems like aya-rs uses very small 10KB minimum log buf size, which might be a bit inadequate with rotating log semantics. > > [0] https://github.com/cilium/ebpf/blob/master/internal/errors.go > https://github.com/cilium/ebpf/blob/master/prog.go#L61
