libbpf: fix ringbuf synchronization, use EPOLLET #5363

ajwerner · 2023-07-18T23:19:30Z

This patch fixes enhances the synchronization between libbpf and the producer in the kernel so that notifications cannot be lost because the producer reads a stale view of the consumer position while the consumer also reads a stale view of either the producer position or the header.

The problem before this change was that nothing enforced a happens before relationship between either of the writes and the subsequent reads.

The use of a sequentially consistent write ensures that the write to the consumer position is either ordered before the producer clears the busy bit, in which case the producer will see that the consumer caught up, or the write will occur after the producer has cleared the busy bit, in which case the new message will be visible.

All of this is in service of using EPOLLET, which will perform fewer wakeups and generally less work. This is borne out in the benchmark data below. Note that without the atomics change, the use of EPOLLET does not work, and the benchmarks and tests show it.

The below raw benchmarks are below (I've omitted the irrelevant ones for brevity). The benchmarks were run on a 32-thread AMD Ryzen 9 7950X 16-Core Processor.

The summary of the results is that the producer is that in almost all cases, the benchmarks are substantially improved. The only case which seems appreciably worse is "Ringbuf sampled, reserve+commit vs output", for the "reserve" case. I guess this makes sense because the consumer piece is more expensive, and the sampled notifications mean there's not a lot of time interacting with epoll.

New:

Single-producer, parallel producer
==================================
rb-libbpf            43.366 ± 0.277M/s (drops 0.848 ± 0.027M/s)

Single-producer, parallel producer, sampled notification
========================================================
rb-libbpf            41.163 ± 0.031M/s (drops 0.000 ± 0.000M/s)

Single-producer, back-to-back mode
==================================
rb-libbpf            60.671 ± 0.274M/s (drops 0.000 ± 0.000M/s)
rb-libbpf-sampled    59.229 ± 0.422M/s (drops 0.000 ± 0.000M/s)

Ringbuf back-to-back, effect of sample rate
===========================================
rb-sampled-1         1.507 ± 0.004M/s (drops 0.000 ± 0.000M/s)
rb-sampled-5         7.095 ± 0.016M/s (drops 0.000 ± 0.000M/s)
rb-sampled-10        13.091 ± 0.046M/s (drops 0.000 ± 0.000M/s)
rb-sampled-25        26.259 ± 0.061M/s (drops 0.000 ± 0.000M/s)
rb-sampled-50        39.831 ± 0.122M/s (drops 0.000 ± 0.000M/s)
rb-sampled-100       51.536 ± 2.984M/s (drops 0.000 ± 0.000M/s)
rb-sampled-250       67.850 ± 1.267M/s (drops 0.000 ± 0.000M/s)
rb-sampled-500       75.257 ± 0.438M/s (drops 0.000 ± 0.000M/s)
rb-sampled-1000      74.939 ± 0.295M/s (drops 0.000 ± 0.000M/s)
rb-sampled-2000      81.481 ± 0.769M/s (drops 0.000 ± 0.000M/s)
rb-sampled-3000      82.637 ± 0.448M/s (drops 0.000 ± 0.000M/s)

Ringbuf back-to-back, reserve+commit vs output
==============================================
reserve              78.142 ± 0.104M/s (drops 0.000 ± 0.000M/s)
output               68.418 ± 0.032M/s (drops 0.000 ± 0.000M/s)

Ringbuf sampled, reserve+commit vs output
=========================================
reserve-sampled      30.577 ± 2.122M/s (drops 0.000 ± 0.000M/s)
output-sampled       30.075 ± 1.089M/s (drops 0.000 ± 0.000M/s)

Single-producer, consumer/producer competing on the same CPU, low batch count
=============================================================================
rb-libbpf            0.570 ± 0.004M/s (drops 0.000 ± 0.000M/s)

Ringbuf, multi-producer contention
==================================
rb-libbpf nr_prod 1  44.359 ± 0.319M/s (drops 0.091 ± 0.027M/s)
rb-libbpf nr_prod 2  23.722 ± 0.024M/s (drops 0.000 ± 0.000M/s)
rb-libbpf nr_prod 3  14.128 ± 0.011M/s (drops 0.000 ± 0.000M/s)
rb-libbpf nr_prod 4  14.896 ± 0.020M/s (drops 0.000 ± 0.000M/s)
rb-libbpf nr_prod 8  6.056 ± 0.061M/s (drops 0.000 ± 0.000M/s)
rb-libbpf nr_prod 12 4.612 ± 0.042M/s (drops 0.000 ± 0.000M/s)
rb-libbpf nr_prod 16 4.684 ± 0.040M/s (drops 0.000 ± 0.000M/s)
rb-libbpf nr_prod 20 5.007 ± 0.046M/s (drops 0.001 ± 0.004M/s)
rb-libbpf nr_prod 24 5.207 ± 0.093M/s (drops 0.006 ± 0.013M/s)
rb-libbpf nr_prod 28 4.951 ± 0.073M/s (drops 0.030 ± 0.069M/s)
rb-libbpf nr_prod 32 4.509 ± 0.069M/s (drops 0.582 ± 0.057M/s)
rb-libbpf nr_prod 36 4.361 ± 0.064M/s (drops 0.733 ± 0.126M/s)
rb-libbpf nr_prod 40 4.261 ± 0.049M/s (drops 0.713 ± 0.116M/s)
rb-libbpf nr_prod 44 4.150 ± 0.207M/s (drops 0.841 ± 0.191M/s)
rb-libbpf nr_prod 48 4.033 ± 0.064M/s (drops 1.009 ± 0.082M/s)
rb-libbpf nr_prod 52 4.025 ± 0.049M/s (drops 1.012 ± 0.069M/s)

Old:

Single-producer, parallel producer
==================================
rb-libbpf            20.755 ± 0.396M/s (drops 0.000 ± 0.000M/s)

Single-producer, parallel producer, sampled notification
========================================================
rb-libbpf            29.347 ± 0.087M/s (drops 0.000 ± 0.000M/s)

Single-producer, back-to-back mode
==================================
rb-libbpf            60.791 ± 0.188M/s (drops 0.000 ± 0.000M/s)
rb-libbpf-sampled    60.125 ± 0.207M/s (drops 0.000 ± 0.000M/s)

Ringbuf back-to-back, effect of sample rate
===========================================
rb-sampled-1         1.534 ± 0.006M/s (drops 0.000 ± 0.000M/s)
rb-sampled-5         7.062 ± 0.029M/s (drops 0.000 ± 0.000M/s)
rb-sampled-10        13.093 ± 0.107M/s (drops 0.000 ± 0.000M/s)
rb-sampled-25        26.292 ± 0.118M/s (drops 0.000 ± 0.000M/s)
rb-sampled-50        40.230 ± 0.030M/s (drops 0.000 ± 0.000M/s)
rb-sampled-100       54.123 ± 0.334M/s (drops 0.000 ± 0.000M/s)
rb-sampled-250       66.054 ± 0.282M/s (drops 0.000 ± 0.000M/s)
rb-sampled-500       76.130 ± 0.648M/s (drops 0.000 ± 0.000M/s)
rb-sampled-1000      80.531 ± 0.169M/s (drops 0.000 ± 0.000M/s)
rb-sampled-2000      83.170 ± 0.376M/s (drops 0.000 ± 0.000M/s)
rb-sampled-3000      83.702 ± 0.046M/s (drops 0.000 ± 0.000M/s)

Ringbuf back-to-back, reserve+commit vs output
==============================================
reserve              77.829 ± 0.178M/s (drops 0.000 ± 0.000M/s)
output               67.974 ± 0.153M/s (drops 0.000 ± 0.000M/s)

Ringbuf sampled, reserve+commit vs output
=========================================
reserve-sampled      33.925 ± 0.101M/s (drops 0.000 ± 0.000M/s)
output-sampled       30.610 ± 0.070M/s (drops 0.000 ± 0.000M/s)

Single-producer, consumer/producer competing on the same CPU, low batch count
=============================================================================
rb-libbpf            0.565 ± 0.002M/s (drops 0.000 ± 0.000M/s)

Ringbuf, multi-producer contention
==================================
rb-libbpf nr_prod 1  18.486 ± 0.067M/s (drops 0.000 ± 0.000M/s)
rb-libbpf nr_prod 2  22.009 ± 0.023M/s (drops 0.000 ± 0.000M/s)
rb-libbpf nr_prod 3  11.908 ± 0.023M/s (drops 0.000 ± 0.000M/s)
rb-libbpf nr_prod 4  11.302 ± 0.031M/s (drops 0.000 ± 0.000M/s)
rb-libbpf nr_prod 8  5.799 ± 0.032M/s (drops 0.000 ± 0.000M/s)
rb-libbpf nr_prod 12 4.296 ± 0.008M/s (drops 0.000 ± 0.000M/s)
rb-libbpf nr_prod 16 4.248 ± 0.005M/s (drops 0.000 ± 0.000M/s)
rb-libbpf nr_prod 20 4.530 ± 0.032M/s (drops 0.000 ± 0.000M/s)
rb-libbpf nr_prod 24 4.607 ± 0.012M/s (drops 0.000 ± 0.000M/s)
rb-libbpf nr_prod 28 4.470 ± 0.017M/s (drops 0.002 ± 0.007M/s)
rb-libbpf nr_prod 32 4.348 ± 0.051M/s (drops 0.703 ± 0.072M/s)
rb-libbpf nr_prod 36 4.248 ± 0.062M/s (drops 0.603 ± 0.102M/s)
rb-libbpf nr_prod 40 4.227 ± 0.051M/s (drops 0.805 ± 0.053M/s)
rb-libbpf nr_prod 44 4.100 ± 0.049M/s (drops 0.828 ± 0.063M/s)
rb-libbpf nr_prod 48 4.056 ± 0.065M/s (drops 0.922 ± 0.083M/s)
rb-libbpf nr_prod 52 4.051 ± 0.053M/s (drops 0.935 ± 0.093M/s)

This patch fixes enhances the synchronization between libbpf and the producer in the kernel so that notifications cannot be lost because the producer reads a stale view of the consumer position while the consumer also reads a stale view of either the producer position or the header. The problem before this change was that nothing enforced a happens before relationship between either of the writes and the subsequent reads. The use of a sequentially consistent write ensures that the write to the consumer position is either ordered before the producer clears the busy bit, in which case the producer will see that the consumer caught up, or the write will occur after the producer has cleared the busy bit, in which case the new message will be visible. All of this is in service of using EPOLLET, which will perform fewer wakeups and generally less work. This is borne out in the benchmark data below. Note that without the atomics change, the use of EPOLLET does not work, and the benchmarks and tests show it. The below raw benchmarks are below (I've omitted the irrelevant ones for brevity). The benchmarks were run on a 32-thread AMD Ryzen 9 7950X 16-Core Processor. The summary of the results is that the producer is that in almost all cases, the benchmarks are substantially improved. The only case which seems appreciably worse is "Ringbuf sampled, reserve+commit vs output", for the "reserve" case. I guess this makes sense because the consumer piece is more expensive, and the sampled notifications mean there's not a lot of time interacting with epoll. New: ``` Single-producer, parallel producer ================================== rb-libbpf 43.366 ± 0.277M/s (drops 0.848 ± 0.027M/s) Single-producer, parallel producer, sampled notification ======================================================== rb-libbpf 41.163 ± 0.031M/s (drops 0.000 ± 0.000M/s) Single-producer, back-to-back mode ================================== rb-libbpf 60.671 ± 0.274M/s (drops 0.000 ± 0.000M/s) rb-libbpf-sampled 59.229 ± 0.422M/s (drops 0.000 ± 0.000M/s) Ringbuf back-to-back, effect of sample rate =========================================== rb-sampled-1 1.507 ± 0.004M/s (drops 0.000 ± 0.000M/s) rb-sampled-5 7.095 ± 0.016M/s (drops 0.000 ± 0.000M/s) rb-sampled-10 13.091 ± 0.046M/s (drops 0.000 ± 0.000M/s) rb-sampled-25 26.259 ± 0.061M/s (drops 0.000 ± 0.000M/s) rb-sampled-50 39.831 ± 0.122M/s (drops 0.000 ± 0.000M/s) rb-sampled-100 51.536 ± 2.984M/s (drops 0.000 ± 0.000M/s) rb-sampled-250 67.850 ± 1.267M/s (drops 0.000 ± 0.000M/s) rb-sampled-500 75.257 ± 0.438M/s (drops 0.000 ± 0.000M/s) rb-sampled-1000 74.939 ± 0.295M/s (drops 0.000 ± 0.000M/s) rb-sampled-2000 81.481 ± 0.769M/s (drops 0.000 ± 0.000M/s) rb-sampled-3000 82.637 ± 0.448M/s (drops 0.000 ± 0.000M/s) Ringbuf back-to-back, reserve+commit vs output ============================================== reserve 78.142 ± 0.104M/s (drops 0.000 ± 0.000M/s) output 68.418 ± 0.032M/s (drops 0.000 ± 0.000M/s) Ringbuf sampled, reserve+commit vs output ========================================= reserve-sampled 30.577 ± 2.122M/s (drops 0.000 ± 0.000M/s) output-sampled 30.075 ± 1.089M/s (drops 0.000 ± 0.000M/s) Single-producer, consumer/producer competing on the same CPU, low batch count ============================================================================= rb-libbpf 0.570 ± 0.004M/s (drops 0.000 ± 0.000M/s) Ringbuf, multi-producer contention ================================== rb-libbpf nr_prod 1 44.359 ± 0.319M/s (drops 0.091 ± 0.027M/s) rb-libbpf nr_prod 2 23.722 ± 0.024M/s (drops 0.000 ± 0.000M/s) rb-libbpf nr_prod 3 14.128 ± 0.011M/s (drops 0.000 ± 0.000M/s) rb-libbpf nr_prod 4 14.896 ± 0.020M/s (drops 0.000 ± 0.000M/s) rb-libbpf nr_prod 8 6.056 ± 0.061M/s (drops 0.000 ± 0.000M/s) rb-libbpf nr_prod 12 4.612 ± 0.042M/s (drops 0.000 ± 0.000M/s) rb-libbpf nr_prod 16 4.684 ± 0.040M/s (drops 0.000 ± 0.000M/s) rb-libbpf nr_prod 20 5.007 ± 0.046M/s (drops 0.001 ± 0.004M/s) rb-libbpf nr_prod 24 5.207 ± 0.093M/s (drops 0.006 ± 0.013M/s) rb-libbpf nr_prod 28 4.951 ± 0.073M/s (drops 0.030 ± 0.069M/s) rb-libbpf nr_prod 32 4.509 ± 0.069M/s (drops 0.582 ± 0.057M/s) rb-libbpf nr_prod 36 4.361 ± 0.064M/s (drops 0.733 ± 0.126M/s) rb-libbpf nr_prod 40 4.261 ± 0.049M/s (drops 0.713 ± 0.116M/s) rb-libbpf nr_prod 44 4.150 ± 0.207M/s (drops 0.841 ± 0.191M/s) rb-libbpf nr_prod 48 4.033 ± 0.064M/s (drops 1.009 ± 0.082M/s) rb-libbpf nr_prod 52 4.025 ± 0.049M/s (drops 1.012 ± 0.069M/s) ``` Old: ``` Single-producer, parallel producer ================================== rb-libbpf 20.755 ± 0.396M/s (drops 0.000 ± 0.000M/s) Single-producer, parallel producer, sampled notification ======================================================== rb-libbpf 29.347 ± 0.087M/s (drops 0.000 ± 0.000M/s) Single-producer, back-to-back mode ================================== rb-libbpf 60.791 ± 0.188M/s (drops 0.000 ± 0.000M/s) rb-libbpf-sampled 60.125 ± 0.207M/s (drops 0.000 ± 0.000M/s) Ringbuf back-to-back, effect of sample rate =========================================== rb-sampled-1 1.534 ± 0.006M/s (drops 0.000 ± 0.000M/s) rb-sampled-5 7.062 ± 0.029M/s (drops 0.000 ± 0.000M/s) rb-sampled-10 13.093 ± 0.107M/s (drops 0.000 ± 0.000M/s) rb-sampled-25 26.292 ± 0.118M/s (drops 0.000 ± 0.000M/s) rb-sampled-50 40.230 ± 0.030M/s (drops 0.000 ± 0.000M/s) rb-sampled-100 54.123 ± 0.334M/s (drops 0.000 ± 0.000M/s) rb-sampled-250 66.054 ± 0.282M/s (drops 0.000 ± 0.000M/s) rb-sampled-500 76.130 ± 0.648M/s (drops 0.000 ± 0.000M/s) rb-sampled-1000 80.531 ± 0.169M/s (drops 0.000 ± 0.000M/s) rb-sampled-2000 83.170 ± 0.376M/s (drops 0.000 ± 0.000M/s) rb-sampled-3000 83.702 ± 0.046M/s (drops 0.000 ± 0.000M/s) Ringbuf back-to-back, reserve+commit vs output ============================================== reserve 77.829 ± 0.178M/s (drops 0.000 ± 0.000M/s) output 67.974 ± 0.153M/s (drops 0.000 ± 0.000M/s) Ringbuf sampled, reserve+commit vs output ========================================= reserve-sampled 33.925 ± 0.101M/s (drops 0.000 ± 0.000M/s) output-sampled 30.610 ± 0.070M/s (drops 0.000 ± 0.000M/s) Single-producer, consumer/producer competing on the same CPU, low batch count ============================================================================= rb-libbpf 0.565 ± 0.002M/s (drops 0.000 ± 0.000M/s) Ringbuf, multi-producer contention ================================== rb-libbpf nr_prod 1 18.486 ± 0.067M/s (drops 0.000 ± 0.000M/s) rb-libbpf nr_prod 2 22.009 ± 0.023M/s (drops 0.000 ± 0.000M/s) rb-libbpf nr_prod 3 11.908 ± 0.023M/s (drops 0.000 ± 0.000M/s) rb-libbpf nr_prod 4 11.302 ± 0.031M/s (drops 0.000 ± 0.000M/s) rb-libbpf nr_prod 8 5.799 ± 0.032M/s (drops 0.000 ± 0.000M/s) rb-libbpf nr_prod 12 4.296 ± 0.008M/s (drops 0.000 ± 0.000M/s) rb-libbpf nr_prod 16 4.248 ± 0.005M/s (drops 0.000 ± 0.000M/s) rb-libbpf nr_prod 20 4.530 ± 0.032M/s (drops 0.000 ± 0.000M/s) rb-libbpf nr_prod 24 4.607 ± 0.012M/s (drops 0.000 ± 0.000M/s) rb-libbpf nr_prod 28 4.470 ± 0.017M/s (drops 0.002 ± 0.007M/s) rb-libbpf nr_prod 32 4.348 ± 0.051M/s (drops 0.703 ± 0.072M/s) rb-libbpf nr_prod 36 4.248 ± 0.062M/s (drops 0.603 ± 0.102M/s) rb-libbpf nr_prod 40 4.227 ± 0.051M/s (drops 0.805 ± 0.053M/s) rb-libbpf nr_prod 44 4.100 ± 0.049M/s (drops 0.828 ± 0.063M/s) rb-libbpf nr_prod 48 4.056 ± 0.065M/s (drops 0.922 ± 0.083M/s) rb-libbpf nr_prod 52 4.051 ± 0.053M/s (drops 0.935 ± 0.093M/s) ```

kernel-patches-daemon-bpf · 2023-07-26T01:27:27Z

Automatically cleaning up stale PR; feel free to reopen if needed

Verifier log avoids printing the same source code line multiple times when a consecutive block of BPF assembly instructions are covered by the same original (C) source code line. This greatly improves verifier log legibility. Unfortunately, this check is imperfect and in production applications it quite often happens that verifier log will have multiple duplicated source lines emitted, for no apparently good reason. E.g., this is excerpt from a real-world BPF application (with register states omitted for clarity): BEFORE ====== ; for (int i = 0; i < STROBE_MAX_MAP_ENTRIES; ++i) { @ strobemeta_probe.bpf.c:394 5369: (07) r8 += 2 ; 5370: (07) r7 += 16 ; ; for (int i = 0; i < STROBE_MAX_MAP_ENTRIES; ++i) { @ strobemeta_probe.bpf.c:394 5371: (07) r9 += 1 ; 5372: (79) r4 = *(u64 *)(r10 -32) ; ; for (int i = 0; i < STROBE_MAX_MAP_ENTRIES; ++i) { @ strobemeta_probe.bpf.c:394 5373: (55) if r9 != 0xf goto pc+2 ; if (i >= map->cnt) @ strobemeta_probe.bpf.c:396 5376: (79) r1 = *(u64 *)(r10 -40) ; 5377: (79) r1 = *(u64 *)(r1 +8) ; ; if (i >= map->cnt) @ strobemeta_probe.bpf.c:396 5378: (dd) if r1 s<= r9 goto pc-5 ; ; descr->key_lens[i] = 0; @ strobemeta_probe.bpf.c:398 5379: (b4) w1 = 0 ; 5380: (6b) *(u16 *)(r8 -30) = r1 ; ; task, data, off, STROBE_MAX_STR_LEN, map->entries[i].key); @ strobemeta_probe.bpf.c:400 5381: (79) r3 = *(u64 *)(r7 -8) ; 5382: (7b) *(u64 *)(r10 -24) = r6 ; ; task, data, off, STROBE_MAX_STR_LEN, map->entries[i].key); @ strobemeta_probe.bpf.c:400 5383: (bc) w6 = w6 ; ; barrier_var(payload_off); @ strobemeta_probe.bpf.c:280 5384: (bf) r2 = r6 ; 5385: (bf) r1 = r4 ; As can be seen, line 394 is emitted thrice, 396 is emitted twice, and line 400 is duplicated as well. Note that there are no intermingling other lines of source code in between these duplicates, so the issue is not compiler reordering assembly instruction such that multiple original source code lines are in effect. It becomes more obvious what's going on if we look at *full* original line info information (using btfdump for this, [0]): #2764: line: insn #5363 --> 394:3 @ ./././strobemeta_probe.bpf.c for (int i = 0; i < STROBE_MAX_MAP_ENTRIES; ++i) { #2765: line: insn #5373 --> 394:21 @ ./././strobemeta_probe.bpf.c for (int i = 0; i < STROBE_MAX_MAP_ENTRIES; ++i) { #2766: line: insn #5375 --> 394:47 @ ./././strobemeta_probe.bpf.c for (int i = 0; i < STROBE_MAX_MAP_ENTRIES; ++i) { #2767: line: insn #5377 --> 394:3 @ ./././strobemeta_probe.bpf.c for (int i = 0; i < STROBE_MAX_MAP_ENTRIES; ++i) { #2768: line: insn #5378 --> 414:10 @ ./././strobemeta_probe.bpf.c return off; We can see that there are four line info records covering instructions #5363 through #5377 (instruction indices are shifted due to subprog instruction being appended to main program), all of them are pointing to the same C source code line #394. But each of them points to a different part of that line, which is denoted by differing column numbers (3, 21, 47, 3). But verifier log doesn't distinguish between parts of the same source code line and doesn't emit this column number information, so for end user it's just a repetitive visual noise. So let's improve the detection of repeated source code line and avoid this. With the changes in this patch, we get this output for the same piece of BPF program log: AFTER ===== ; for (int i = 0; i < STROBE_MAX_MAP_ENTRIES; ++i) { @ strobemeta_probe.bpf.c:394 5369: (07) r8 += 2 ; 5370: (07) r7 += 16 ; 5371: (07) r9 += 1 ; 5372: (79) r4 = *(u64 *)(r10 -32) ; 5373: (55) if r9 != 0xf goto pc+2 ; if (i >= map->cnt) @ strobemeta_probe.bpf.c:396 5376: (79) r1 = *(u64 *)(r10 -40) ; 5377: (79) r1 = *(u64 *)(r1 +8) ; 5378: (dd) if r1 s<= r9 goto pc-5 ; ; descr->key_lens[i] = 0; @ strobemeta_probe.bpf.c:398 5379: (b4) w1 = 0 ; 5380: (6b) *(u16 *)(r8 -30) = r1 ; ; task, data, off, STROBE_MAX_STR_LEN, map->entries[i].key); @ strobemeta_probe.bpf.c:400 5381: (79) r3 = *(u64 *)(r7 -8) ; 5382: (7b) *(u64 *)(r10 -24) = r6 ; 5383: (bc) w6 = w6 ; ; barrier_var(payload_off); @ strobemeta_probe.bpf.c:280 5384: (bf) r2 = r6 ; 5385: (bf) r1 = r4 ; All the duplication is gone and the log is cleaner and less distracting. [0] https://github.com/anakryiko/btfdump Signed-off-by: Andrii Nakryiko <[email protected]>

Verifier log avoids printing the same source code line multiple times when a consecutive block of BPF assembly instructions are covered by the same original (C) source code line. This greatly improves verifier log legibility. Unfortunately, this check is imperfect and in production applications it quite often happens that verifier log will have multiple duplicated source lines emitted, for no apparently good reason. E.g., this is excerpt from a real-world BPF application (with register states omitted for clarity): BEFORE ====== ; for (int i = 0; i < STROBE_MAX_MAP_ENTRIES; ++i) { @ strobemeta_probe.bpf.c:394 5369: (07) r8 += 2 ; 5370: (07) r7 += 16 ; ; for (int i = 0; i < STROBE_MAX_MAP_ENTRIES; ++i) { @ strobemeta_probe.bpf.c:394 5371: (07) r9 += 1 ; 5372: (79) r4 = *(u64 *)(r10 -32) ; ; for (int i = 0; i < STROBE_MAX_MAP_ENTRIES; ++i) { @ strobemeta_probe.bpf.c:394 5373: (55) if r9 != 0xf goto pc+2 ; if (i >= map->cnt) @ strobemeta_probe.bpf.c:396 5376: (79) r1 = *(u64 *)(r10 -40) ; 5377: (79) r1 = *(u64 *)(r1 +8) ; ; if (i >= map->cnt) @ strobemeta_probe.bpf.c:396 5378: (dd) if r1 s<= r9 goto pc-5 ; ; descr->key_lens[i] = 0; @ strobemeta_probe.bpf.c:398 5379: (b4) w1 = 0 ; 5380: (6b) *(u16 *)(r8 -30) = r1 ; ; task, data, off, STROBE_MAX_STR_LEN, map->entries[i].key); @ strobemeta_probe.bpf.c:400 5381: (79) r3 = *(u64 *)(r7 -8) ; 5382: (7b) *(u64 *)(r10 -24) = r6 ; ; task, data, off, STROBE_MAX_STR_LEN, map->entries[i].key); @ strobemeta_probe.bpf.c:400 5383: (bc) w6 = w6 ; ; barrier_var(payload_off); @ strobemeta_probe.bpf.c:280 5384: (bf) r2 = r6 ; 5385: (bf) r1 = r4 ; As can be seen, line 394 is emitted thrice, 396 is emitted twice, and line 400 is duplicated as well. Note that there are no intermingling other lines of source code in between these duplicates, so the issue is not compiler reordering assembly instruction such that multiple original source code lines are in effect. It becomes more obvious what's going on if we look at *full* original line info information (using btfdump for this, [0]): #2764: line: insn #5363 --> 394:3 @ ./././strobemeta_probe.bpf.c for (int i = 0; i < STROBE_MAX_MAP_ENTRIES; ++i) { #2765: line: insn #5373 --> 394:21 @ ./././strobemeta_probe.bpf.c for (int i = 0; i < STROBE_MAX_MAP_ENTRIES; ++i) { #2766: line: insn #5375 --> 394:47 @ ./././strobemeta_probe.bpf.c for (int i = 0; i < STROBE_MAX_MAP_ENTRIES; ++i) { #2767: line: insn #5377 --> 394:3 @ ./././strobemeta_probe.bpf.c for (int i = 0; i < STROBE_MAX_MAP_ENTRIES; ++i) { #2768: line: insn #5378 --> 414:10 @ ./././strobemeta_probe.bpf.c return off; We can see that there are four line info records covering instructions #5363 through #5377 (instruction indices are shifted due to subprog instruction being appended to main program), all of them are pointing to the same C source code line #394. But each of them points to a different part of that line, which is denoted by differing column numbers (3, 21, 47, 3). But verifier log doesn't distinguish between parts of the same source code line and doesn't emit this column number information, so for end user it's just a repetitive visual noise. So let's improve the detection of repeated source code line and avoid this. With the changes in this patch, we get this output for the same piece of BPF program log: AFTER ===== ; for (int i = 0; i < STROBE_MAX_MAP_ENTRIES; ++i) { @ strobemeta_probe.bpf.c:394 5369: (07) r8 += 2 ; 5370: (07) r7 += 16 ; 5371: (07) r9 += 1 ; 5372: (79) r4 = *(u64 *)(r10 -32) ; 5373: (55) if r9 != 0xf goto pc+2 ; if (i >= map->cnt) @ strobemeta_probe.bpf.c:396 5376: (79) r1 = *(u64 *)(r10 -40) ; 5377: (79) r1 = *(u64 *)(r1 +8) ; 5378: (dd) if r1 s<= r9 goto pc-5 ; ; descr->key_lens[i] = 0; @ strobemeta_probe.bpf.c:398 5379: (b4) w1 = 0 ; 5380: (6b) *(u16 *)(r8 -30) = r1 ; ; task, data, off, STROBE_MAX_STR_LEN, map->entries[i].key); @ strobemeta_probe.bpf.c:400 5381: (79) r3 = *(u64 *)(r7 -8) ; 5382: (7b) *(u64 *)(r10 -24) = r6 ; 5383: (bc) w6 = w6 ; ; barrier_var(payload_off); @ strobemeta_probe.bpf.c:280 5384: (bf) r2 = r6 ; 5385: (bf) r1 = r4 ; All the duplication is gone and the log is cleaner and less distracting. [0] https://github.com/anakryiko/btfdump Signed-off-by: Andrii Nakryiko <[email protected]> Link: https://lore.kernel.org/r/[email protected] Signed-off-by: Alexei Starovoitov <[email protected]>

kernel-patches-daemon-bpf bot force-pushed the bpf-next_base branch 3 times, most recently from 9b6f91a to bb62313 Compare July 19, 2023 00:36

ajwerner force-pushed the ring_buf_epollet branch from cfa80f7 to 4950bfd Compare July 19, 2023 01:25

kernel-patches-daemon-bpf bot force-pushed the bpf-next_base branch 12 times, most recently from bc7bf04 to 037bc8f Compare July 26, 2023 00:22

kernel-patches-daemon-bpf bot closed this Jul 26, 2023

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

Uh oh!

libbpf: fix ringbuf synchronization, use EPOLLET #5363

libbpf: fix ringbuf synchronization, use EPOLLET #5363

Uh oh!

ajwerner commented Jul 18, 2023

Uh oh!

kernel-patches-daemon-bpf bot commented Jul 26, 2023

Uh oh!

Uh oh!

libbpf: fix ringbuf synchronization, use EPOLLET #5363

libbpf: fix ringbuf synchronization, use EPOLLET #5363

Uh oh!

Conversation

ajwerner commented Jul 18, 2023

Uh oh!

kernel-patches-daemon-bpf bot commented Jul 26, 2023

Uh oh!

Uh oh!