Message-ID: <CANpmjNNnkv1UH=RLaeejFicicRZFn4D2sChmppoFdOfJYY_0hw@mail.gmail.com>
Date: Fri, 13 Oct 2023 09:21:05 +0200
From: Marco Elver <elver@...gle.com>
To: Mirsad Goran Todorovac <mirsad.todorovac@....unizg.hr>
Cc: Heiner Kallweit <hkallweit1@...il.com>, netdev@...r.kernel.org, 
	linux-kernel@...r.kernel.org, nic_swsd@...ltek.com, 
	"David S. Miller" <davem@...emloft.net>, Eric Dumazet <edumazet@...gle.com>, 
	Jakub Kicinski <kuba@...nel.org>, Paolo Abeni <pabeni@...hat.com>
Subject: Re: [PATCH RFC v1 1/3] r8169: fix the KCSAN reported data-race in
 rtl_tx() while reading tp->cur_tx

On Fri, 13 Oct 2023 at 07:01, Mirsad Goran Todorovac
<mirsad.todorovac@....unizg.hr> wrote:
>
> On 9/28/2023 8:02 AM, Marco Elver wrote:
> > On Wed, 27 Sept 2023 at 21:52, Heiner Kallweit <hkallweit1@...il.com> wrote:
> >>
> >> On 27.09.2023 20:41, Mirsad Goran Todorovac wrote:
> >>> KCSAN reported the following data-race:
> >>>
> >>> ==================================================================
> >>> BUG: KCSAN: data-race in rtl8169_poll [r8169] / rtl8169_start_xmit [r8169]
> >>>
> >>> write (marked) to 0xffff888102474b74 of 4 bytes by task 5358 on cpu 29:
> >>> rtl8169_start_xmit (drivers/net/ethernet/realtek/r8169_main.c:4254) r8169
> >>> dev_hard_start_xmit (./include/linux/netdevice.h:4889 ./include/linux/netdevice.h:4903 net/core/dev.c:3544 net/core/dev.c:3560)
> >>> sch_direct_xmit (net/sched/sch_generic.c:342)
> >>> __dev_queue_xmit (net/core/dev.c:3817 net/core/dev.c:4306)
> >>> ip_finish_output2 (./include/linux/netdevice.h:3082 ./include/net/neighbour.h:526 ./include/net/neighbour.h:540 net/ipv4/ip_output.c:233)
> >>> __ip_finish_output (net/ipv4/ip_output.c:311 net/ipv4/ip_output.c:293)
> >>> ip_finish_output (net/ipv4/ip_output.c:328)
> >>> ip_output (net/ipv4/ip_output.c:435)
> >>> ip_send_skb (./include/net/dst.h:458 net/ipv4/ip_output.c:127 net/ipv4/ip_output.c:1486)
> >>> udp_send_skb (net/ipv4/udp.c:963)
> >>> udp_sendmsg (net/ipv4/udp.c:1246)
> >>> inet_sendmsg (net/ipv4/af_inet.c:840 (discriminator 4))
> >>> sock_sendmsg (net/socket.c:730 net/socket.c:753)
> >>> __sys_sendto (net/socket.c:2177)
> >>> __x64_sys_sendto (net/socket.c:2185)
> >>> do_syscall_64 (arch/x86/entry/common.c:50 arch/x86/entry/common.c:80)
> >>> entry_SYSCALL_64_after_hwframe (arch/x86/entry/entry_64.S:120)
> >>>
> >>> read to 0xffff888102474b74 of 4 bytes by interrupt on cpu 21:
> >>> rtl8169_poll (drivers/net/ethernet/realtek/r8169_main.c:4397 drivers/net/ethernet/realtek/r8169_main.c:4581) r8169
> >>> __napi_poll (net/core/dev.c:6527)
> >>> net_rx_action (net/core/dev.c:6596 net/core/dev.c:6727)
> >>> __do_softirq (kernel/softirq.c:553)
> >>> __irq_exit_rcu (kernel/softirq.c:427 kernel/softirq.c:632)
> >>> irq_exit_rcu (kernel/softirq.c:647)
> >>> common_interrupt (arch/x86/kernel/irq.c:247 (discriminator 14))
> >>> asm_common_interrupt (./arch/x86/include/asm/idtentry.h:636)
> >>> cpuidle_enter_state (drivers/cpuidle/cpuidle.c:291)
> >>> cpuidle_enter (drivers/cpuidle/cpuidle.c:390)
> >>> call_cpuidle (kernel/sched/idle.c:135)
> >>> do_idle (kernel/sched/idle.c:219 kernel/sched/idle.c:282)
> >>> cpu_startup_entry (kernel/sched/idle.c:378 (discriminator 1))
> >>> start_secondary (arch/x86/kernel/smpboot.c:210 arch/x86/kernel/smpboot.c:294)
> >>> secondary_startup_64_no_verify (arch/x86/kernel/head_64.S:433)
> >>>
> >>> value changed: 0x002f4815 -> 0x002f4816
> >>>
> >>> Reported by Kernel Concurrency Sanitizer on:
> >>> CPU: 21 PID: 0 Comm: swapper/21 Tainted: G             L     6.6.0-rc2-kcsan-00143-gb5cbe7c00aa0 #41
> >>> Hardware name: ASRock X670E PG Lightning/X670E PG Lightning, BIOS 1.21 04/26/2023
> >>> ==================================================================
> >>>
> >>> The write side of drivers/net/ethernet/realtek/r8169_main.c is:
> >>> ==================
> >>>     4251         /* rtl_tx needs to see descriptor changes before updated tp->cur_tx */
> >>>     4252         smp_wmb();
> >>>     4253
> >>>   → 4254         WRITE_ONCE(tp->cur_tx, tp->cur_tx + frags + 1);
> >>>     4255
> >>>     4256         stop_queue = !netif_subqueue_maybe_stop(dev, 0, rtl_tx_slots_avail(tp),
> >>>     4257                                                 R8169_TX_STOP_THRS,
> >>>     4258                                                 R8169_TX_START_THRS);
> >>>
> >>> The read side is the function rtl_tx():
> >>>
> >>>     4355 static void rtl_tx(struct net_device *dev, struct rtl8169_private *tp,
> >>>     4356                    int budget)
> >>>     4357 {
> >>>     4358         unsigned int dirty_tx, bytes_compl = 0, pkts_compl = 0;
> >>>     4359         struct sk_buff *skb;
> >>>     4360
> >>>     4361         dirty_tx = tp->dirty_tx;
> >>>     4362
> >>>     4363         while (READ_ONCE(tp->cur_tx) != dirty_tx) {
> >>>     4364                 unsigned int entry = dirty_tx % NUM_TX_DESC;
> >>>     4365                 u32 status;
> >>>     4366
> >>>     4367                 status = le32_to_cpu(tp->TxDescArray[entry].opts1);
> >>>     4368                 if (status & DescOwn)
> >>>     4369                         break;
> >>>     4370
> >>>     4371                 skb = tp->tx_skb[entry].skb;
> >>>     4372                 rtl8169_unmap_tx_skb(tp, entry);
> >>>     4373
> >>>     4374                 if (skb) {
> >>>     4375                         pkts_compl++;
> >>>     4376                         bytes_compl += skb->len;
> >>>     4377                         napi_consume_skb(skb, budget);
> >>>     4378                 }
> >>>     4379                 dirty_tx++;
> >>>     4380         }
> >>>     4381
> >>>     4382         if (tp->dirty_tx != dirty_tx) {
> >>>     4383                 dev_sw_netstats_tx_add(dev, pkts_compl, bytes_compl);
> >>>     4384                 WRITE_ONCE(tp->dirty_tx, dirty_tx);
> >>>     4385
> >>>     4386                 netif_subqueue_completed_wake(dev, 0, pkts_compl, bytes_compl,
> >>>     4387                                               rtl_tx_slots_avail(tp),
> >>>     4388                                               R8169_TX_START_THRS);
> >>>     4389                 /*
> >>>     4390                  * 8168 hack: TxPoll requests are lost when the Tx packets are
> >>>     4391                  * too close. Let's kick an extra TxPoll request when a burst
> >>>     4392                  * of start_xmit activity is detected (if it is not detected,
> >>>     4393                  * it is slow enough). -- FR
> >>>     4394                  * If skb is NULL then we come here again once a tx irq is
> >>>     4395                  * triggered after the last fragment is marked transmitted.
> >>>     4396                  */
> >>>   → 4397                 if (tp->cur_tx != dirty_tx && skb)
> >>>     4398                         rtl8169_doorbell(tp);
> >>>     4399         }
> >>>     4400 }
> >>>
> >>> Obviously from the code, an earlier detected data-race for tp->cur_tx was fixed in the
> >>> line 4363:
> >>>
> >>>     4363         while (READ_ONCE(tp->cur_tx) != dirty_tx) {
> >>>
> >>> but the same solution is required for protecting the other access to tp->cur_tx:
> >>>
> >>>   → 4397                 if (READ_ONCE(tp->cur_tx) != dirty_tx && skb)
> >>>     4398                         rtl8169_doorbell(tp);
> >>>
> >>> The write in the line 4254 is protected with WRITE_ONCE(), but the read in the line 4397
> >>> might have suffered read tearing under some compiler optimisations.
> >>>
> >>> The fix eliminated the KCSAN data-race report for this bug.
> >>>
> >>> It is yet to be evaluated what happens if tp->cur_tx changes between the test in line 4363
> >>> and line 4397. This test should certainly not be cached by the compiler in some register
> >>> for such a long time, while asynchronous writes to tp->cur_tx might have occurred in line
> >>> 4254 in the meantime.
> >>>
> >>
> >> netif_subqueue_completed_wake() has barriers ensuring that no cached value for tp->cur_tx
> >> is used in line 4397. I'm not aware of any reported issues with an obvious link to the
> >> potentential issue you describe.
> >> I don't have a strong opinion on these patches. They shouldn't hurt, and if they make
> >> KCSAN happy, why not.
> >
> > Barries don't protect unmarked accesses from being miscompiled. So the
> > use of barriers and marked accesses like READ_ONCE() is correct:
> > https://git.kernel.org/pub/scm/linux/kernel/git/torvalds/linux.git/tree/tools/memory-model/Documentation/access-marking.txt
> > That said, actually encountering a miscompilation depends on
> > architecture and compiler. Using the right marked accesses just
> > ensures things don't suddenly break because the compiler decided to be
> > a little more clever.
> >
> >>> Fixes: 94d8a98e6235c ("r8169: reduce number of workaround doorbell rings")
> >>> Cc: Heiner Kallweit <hkallweit1@...il.com>
> >>> Cc: nic_swsd@...ltek.com
> >>> Cc: "David S. Miller" <davem@...emloft.net>
> >>> Cc: Eric Dumazet <edumazet@...gle.com>
> >>> Cc: Jakub Kicinski <kuba@...nel.org>
> >>> Cc: Paolo Abeni <pabeni@...hat.com>
> >>> Cc: Marco Elver <elver@...gle.com>
> >>> Cc: netdev@...r.kernel.org
> >>> Link: https://lore.kernel.org/lkml/dc7fc8fa-4ea4-e9a9-30a6-7c83e6b53188@alu.unizg.hr/
> >>> Signed-off-by: Mirsad Goran Todorovac <mirsad.todorovac@....unizg.hr>
> >
> > Acked-by: Marco Elver <elver@...gle.com>
>
> Hi, Marco,
>
> Does this Acked-by: cover all of the [123]/3 in the patch series?

Technically, no. (Only if this was the cover lettter i.e. 0/n)

Send the non-RFC separately and I'll ack them.

Powered by blists - more mailing lists