Re: [PATCH net-next 2/2] net: optimize skb_postpull_rcsum()

On Thu, Dec 02, 2021 at 11:32:09AM -0800, Eric Dumazet wrote:

On Thu, Dec 2, 2021 at 8:29 AM Vladimir Oltean [off-list ref] wrote:

quoted

On Thu, Dec 02, 2021 at 06:51:47AM -0800, Eric Dumazet wrote:

quoted

Hi Vladimir

quoted

I am seeing some errors after this patch, and I am not able to
understand why. Specifically, __skb_gro_checksum_complete() hits this
condition:

There were two patches, one for GRO, one for skb_postpull_rcsum()

I am a bit confused by your report. Which one is causing problems ?

I'm sorry, indeed it seems that I missed to provide that info.
Anyway, it is the skb_postpull_rcsum() call from the DSA switch driver,
that I pointed to, which seems to be problematic.

[  754.211845] mscc_felix 0000:00:00.5 swp0: hw csum failure
[  754.217670] skb len=64 headroom=118 headlen=64 tailroom=1546
[  754.217670] mac=(84,14) net=(98,20) trans=118
[  754.217670] shinfo(txflags=0 nr_frags=0 gso(size=0 type=0 segs=0))
[  754.217670] csum(0x0 ip_summed=2 complete_sw=0 valid=0 level=0)
[  754.217670] hash(0x0 sw=0 l4=0) proto=0x0800 pkttype=0 iif=9
[  754.246905] dev name=swp0 feat=0x0x0002000000195829
[  754.253200] skb headroom: 00000000: ef be ad de ef be ad de ef be ad de ef be ad de
[  754.261751] skb headroom: 00000010: ef be ad de ef be ad de ef be ad de ef be ad de
[  754.269444] skb headroom: 00000020: ef be ad de ef be ad de ef be ad de ef be ad de
[  754.277135] skb headroom: 00000030: ef be ad de ef be ad de ef be ad de ef be ad de
[  754.284826] skb headroom: 00000040: 88 80 00 0a 00 3e 6b e3 36 a1 01 80 00 00 00 0f
[  754.292516] skb headroom: 00000050: 00 10 00 00 d2 ee 27 92 2d 6c 6a b6 a6 22 19 47
[  754.300207] skb headroom: 00000060: 08 00 45 00 00 54 2d 7c 00 00 40 01 03 d9 c0 a8
[  754.307897] skb headroom: 00000070: 64 02 c0 a8 64 01
[  754.312971] skb linear:   00000000: 00 00 60 4d 03 af 00 01 77 eb a8 61 00 00 00 00
[  754.320662] skb linear:   00000010: b6 e2 06 00 00 00 00 00 10 11 12 13 14 15 16 17
[  754.328352] skb linear:   00000020: 18 19 1a 1b 1c 1d 1e 1f 20 21 22 23 24 25 26 27
[  754.336042] skb linear:   00000030: 28 29 2a 2b 2c 2d 2e 2f 30 31 32 33 34 35 36 37
[  754.343732] skb tailroom: 00000000: 00 00 00 00 00 00 00 00 00 00 ef be ad de ef be
[  754.351423] skb tailroom: 00000010: ad de ef be ad de ef be ad de ef be ad de ef be
(irrelevant tailroom trimmed)
[  755.088130] CPU: 0 PID: 0 Comm: swapper/0 Not tainted 5.16.0-rc3-next-20211202-07010-ga9b9500ffaac-dirty #1531
[  755.098169] Hardware name: LS1028A RDB Board (DT)
[  755.102885] Call trace:
[  755.105333]  dump_backtrace+0x0/0x1ac
[  755.109016]  show_stack+0x18/0x70
[  755.112341]  dump_stack_lvl+0x68/0x84
[  755.116022]  dump_stack+0x18/0x34
[  755.119345]  netdev_rx_csum_fault+0x60/0x64
[  755.123549]  __skb_checksum_complete+0x104/0x10c
[  755.128180]  icmp_rcv+0x9c/0x3f0
[  755.131421]  ip_protocol_deliver_rcu+0x40/0x220
[  755.135965]  ip_local_deliver_finish+0x68/0x84
[  755.140421]  ip_local_deliver+0x7c/0x120
[  755.144353]  ip_sublist_rcv_finish+0x48/0x70
[  755.148643]  ip_sublist_rcv+0x168/0x1f0
[  755.152489]  ip_list_rcv+0xf8/0x1a0
[  755.155985]  __netif_receive_skb_list_core+0x184/0x214
[  755.161142]  netif_receive_skb_list_internal+0x180/0x29c
[  755.166471]  napi_complete_done+0x68/0x1bc
[  755.170581]  gro_cell_poll+0x80/0xa0
[  755.174176]  __napi_poll+0x38/0x184
[  755.177674]  net_rx_action+0xe8/0x280
[  755.181347]  __do_softirq+0x124/0x2a0
[  755.185019]  __irq_exit_rcu+0xe4/0x100
[  755.188782]  irq_exit_rcu+0x10/0x1c
[  755.192278]  el1_interrupt+0x38/0x84
[  755.195864]  el1h_64_irq_handler+0x18/0x24
[  755.199972]  el1h_64_irq+0x78/0x7c
[  755.203380]  cpuidle_enter_state+0x12c/0x2f0
[  755.207671]  cpuidle_enter+0x38/0x50
[  755.211256]  do_idle+0x214/0x29c
[  755.214495]  cpu_startup_entry+0x24/0x80
[  755.218428]  rest_init+0xe4/0xf4
[  755.221664]  arch_call_rest_init+0x10/0x1c
[  755.225778]  start_kernel+0x628/0x668
[  755.229450]  __primary_switched+0xc0/0xc8

quoted

quoted

There seems to be a disparity when the skb->csum is calculated by
skb_postpull_rcsum as zero. Before, it was calculated as 0xffff.

skb->csum is 32bit, so there are about 2^16 different values for a
given Internet checksum

I meant 0xffffffff, sorry. It is visible in the skb_dump output that it
was 0xffffffff before and now it is 0.

quoted

quoted

Do you have some suggestions as to what may be wrong? Thanks.

What kind of traffic is triggering the fault ? TCP, UDP, something else ?

The simplest to reproduce would be for ICMP. I'm pretty sure I had a
stack trace with TCP as well, but I don't seem to be able to reproduce
that right now.

quoted

Do you have a stack trace to provide, because it is not clear from
where the issue is detected.

Thanks Vladimir

I think that maybe the issue is that the initial skb->csum is zero,
and the csum_parttial(removed_block) is also zero.

But the initial skb->csum should not be zero if you have a non " all
zero"  frame.

Can you double check this in drivers/net/ethernet/freescale/enetc/enetc.c ?

To me it looks like the strange part is that the checksum of the removed
block (printed by me as "csum_partial(start, len, 0)" inside
skb_postpull_rcsum()) is the same as the skb->csum itself.

[   66.287583] fsl_enetc 0000:00:00.2 eno2: enetc_get_offloads 991: skb 0xffff4050c3671f00 csum 0x3c1d
[   66.296716] skb csum of 20 bytes (20 to the left of skb->data) using old method: 0x0, new method: 0xffffffff, orig csum 0x3c1d, csum of removed block 0x3c1d
[   66.310786] skb len=84 headroom=98 headlen=84 tailroom=1546
[   66.310786] mac=(84,-6) net=(78,0) trans=78
[   66.310786] shinfo(txflags=0 nr_frags=0 gso(size=0 type=0 segs=0))
[   66.310786] csum(0xffffffff ip_summed=2 complete_sw=0 valid=0 level=0)
[   66.310786] hash(0x0 sw=0 l4=0) proto=0x00f8 pkttype=3 iif=7
[   66.338997] dev name=eno2 feat=0x0x00020100001149a9
[   66.343904] skb headroom: 00000000: 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
[   66.351600] skb headroom: 00000010: 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
[   66.359295] skb headroom: 00000020: 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
[   66.366990] skb headroom: 00000030: 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
[   66.374685] skb headroom: 00000040: 88 80 00 0a 00 38 c1 17 3d 01 01 80 00 00 08 0f
[   66.382379] skb headroom: 00000050: 00 10 00 00 52 f3 98 af f9 8c d2 ee 27 92 2d 6c
[   66.390073] skb headroom: 00000060: 08 00
[   66.394105] skb linear:   00000000: 45 00 00 54 c8 59 40 00 40 01 28 fb c0 a8 64 01
[   66.401799] skb linear:   00000010: c0 a8 64 02 08 00 ee 94 06 98 00 04 03 2e a9 61
[   66.409493] skb linear:   00000020: 00 00 00 00 8b 6c 0c 00 00 00 00 00 10 11 12 13
[   66.417187] skb linear:   00000030: 14 15 16 17 18 19 1a 1b 1c 1d 1e 1f 20 21 22 23
[   66.424880] skb linear:   00000040: 24 25 26 27 28 29 2a 2b 2c 2d 2e 2f 30 31 32 33
[   66.432574] skb linear:   00000050: 34 35 36 37
[   66.437128] skb tailroom: 00000000: 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
[   67.181735] fsl_enetc 0000:00:00.2 eno2: ocelot_rcv 131: skb 0xffff4050c3671f00 csum before skb_postpull_rcsum 0x3c1d, after 0xffffffff

This isn't the case for some other traffic streams, here is some iperf3 TCP:

[   52.336847] fsl_enetc 0000:00:00.2 eno2: enetc_get_offloads 991: skb 0xffff4050c44ab500 csum 0x18ce
[   52.345930] fsl_enetc 0000:00:00.2 eno2: enetc_get_offloads 991: skb 0xffff4050c3671f00 csum 0x18ce
[   52.355014] fsl_enetc 0000:00:00.2 eno2: enetc_get_offloads 991: skb 0xffff4050c3671e00 csum 0x18ce
[   52.397629] fsl_enetc 0000:00:00.2 eno2: ocelot_rcv 131: skb 0xffff4050c44ab500 csum before skb_postpull_rcsum 0x18ce, after 0xffffdcb0
[   52.409853] fsl_enetc 0000:00:00.2 eno2: ocelot_rcv 131: skb 0xffff4050c3671f00 csum before skb_postpull_rcsum 0x18ce, after 0xffffdcb0
[   52.422076] fsl_enetc 0000:00:00.2 eno2: ocelot_rcv 131: skb 0xffff4050c3671e00 csum before skb_postpull_rcsum 0x18ce, after 0xffffdcb0

When skb->csum isn't equal to the csum of the removed block, the two
implementations of skb_postpull_rcsum() agree.