e1000: resume and io_resume bring the device back up without rtnl_lock and deadlock against e1000_reset_task on the NAPI state machine

e1000: resume and io_resume bring the device back up without rtnl_lock and deadlock against e1000_reset_task on the NAPI state machine

[徐晗翔]

[-- Attachment #1: Type: text/plain, Size: 9455 bytes --]

Both e1000 device-recovery paths (e1000_resume() after system
suspend and e1000_io_resume() after a PCI Error Recovery reset) call
e1000_up() while holding no lock at all, so a concurrently running
e1000_reset_task (which is RTNL-protected) slips past the
__E1000_DOWN gate that the recovery path itself just opened, parks in
napi_disable() holding the netdev instance lock and RTNL while
waiting for NAPI_STATE_SCHED to clear -- an event whose only producer
is the recovery thread's napi_enable(), which needs that very lock --
an unresolvable mutual wait that leaves RTNL held forever, hanging
every network configuration operation on the system and preventing
device_resume() from ever completing.
The reset_task work survives system suspend by construction
(system_wq is not freezable and the CPUs are halted, so a pre-suspend
scheduled reset_task cannot run until resume), and in the PCI ER case
the AER error itself produces it (hardware upset -> TX hang -> dev
watchdog -> ndo_tx_timeout -> schedule_work) -- the async opponent is
not a coincidence but part of the same event chain.  I verified the
deadlock on a pristine Linux 7.3 (KASAN kernel, no source
modification) with a probe module that only widens the natural ~10 ms
window: both sides of the mutual wait were observed directly (the
reset_task parked inside napi_disable holding the lock, and the
resume thread blocking on napi_enable for the same lock), after
which resume never completes and the host cannot wake the guest.
The sibling drivers handle both contexts correctly (e1000e wraps its
thaw path in rtnl_lock() and reuses it for io_resume; igb_io_resume()
takes rtnl_lock() and re-checks its DOWN bit) -- e1000 is the only
driver of the family unprotected in both.  Recovery requires a
reboot; triggering is suspend/resume cycling (or an AER event) under
ordinary network load, i.e. a local denial of service.
The detailed description:
* Test environment / affected version
  Linux version 7.3.0 (gcc 13.3.0, GNU ld 2.42) #1 SMP PREEMPT_DYNAMIC
  -- vanilla mainline 7.3 release tarball (kernel.org), KASAN enabled,
  source unmodified.  QEMU/KVM x86_64 guest with an emulated e1000 NIC
  on a user network; real S3 suspend ("echo mem > /sys/power/state")
  with RTC wakealarm.  The verification instrument (attached) is a
  loadable kprobe module; it changes timing only.
* The two unprotected recovery paths (drivers/net/ethernet/intel/
  e1000/e1000_main.c, 7.3 line numbers)
  - e1000_resume() (:5161-5204): no rtnl_lock, no __E1000_RESETTING
    participation; when netif_running(): request_irq, e1000_reset(),
    then e1000_up().
  - e1000_io_resume() (:5311-5326): same shape ("Implementation
    resembles the second-half of the e1000_resume routine"); when
    netif_running(): e1000_up() + netif_device_attach(), no lock.
  Their locked counterparts that create the precondition are:
  __e1000_shutdown() under rtnl_lock() (calls e1000_down(),
  :5084-5086) for the PM case, and e1000_io_error_detected() under
  rtnl_lock() (:5247-5260, calls e1000_down() when running) for the
  ER case.  Both leave __E1000_DOWN=1 and the NAPI in its
  disabled state, i.e. NAPI_STATE_SCHED=1.
* The gate and the deadlock
  e1000_up() order (:381-399):
      e1000_configure(adapter);                 /* :386, DOWN still 1 */
      clear_bit(__E1000_DOWN, &adapter->flags); /* :388  <-- gate    */
      napi_enable(&adapter->napi);              /* :390              */
  The async opponent, e1000_reset_task (:3503-3512): rtnl_lock();
  e1000_reinit_locked(); rtnl_unlock().  e1000_reinit_locked()
  (:531-543) spins on __E1000_RESETTING, then checks
  test_bit(__E1000_DOWN) at :537 -- the check the recovery path's
  clear_bit() at :388 flips.  If reset_task reads DOWN==0 it enters
  e1000_down() (:481-529; includes msleep(10) at :500) and reaches
  napi_disable() at :513.
  The core-level amplifier: napi_disable() runs under the netdev
  instance lock and its wait loop has no timeout
  (net/core/dev.c:7742-7747; the loop at :7712-7715 does
  usleep_range while holding the lock, waiting for
  NAPI_STATE_SCHED).  A freshly added or disabled NAPI has SCHED=1
  (net/core/dev.c:7679-7680); the ONLY operation that clears it is
  napi_enable() -- which must take the same instance lock
  (dev.c:7777-7782).  With no poll running (IRQs not yet enabled in
  the recovery flow), the wait can only be satisfied by the other
  thread of the pair:
      reset_task : napi_disable() holds netdev_lock + RTNL,
                   waits forever for SCHED to clear
      resume     : napi_enable() (the only SCHED clearer)
                   blocks forever on netdev_lock
  The harmful window is the resume thread being preempted/delayed
  >= ~10 ms between the two adjacent statements :388 and :390 (the
  reset_task needs ~10 ms from its DOWN check to napi_disable
  because of the msleep(10) in e1000_down), plus the reset_task
  entering the lock first.  That is an ordinary preemption quantum
  on a loaded, RT, or virtualized system.  All other interleavings
  are safe: reset_task reading DOWN before the gate skips reinit in
  a few instructions; napi_enable() winning the lock first makes the
  later napi_disable() pass instantly (SCHED already cleared) and
  the pair completes normally; the double-napi_enable BUG_ON is
  unreachable (it would need the whole >=10 ms reinit inside the
  gap between two adjacent statements).
* Why the opponent always exists
  - PM context: reset_task is scheduled by e1000_tx_timeout() or by
    e1000_watchdog() on "link lost with outstanding TX" -- ordinary
    conditions under load.  system_wq is not freezable and S3 halts
    the CPUs, so any reset_task scheduled before suspend provably
    survives to resume time (it simply cannot run during suspend).
  - PCI ER context: the AER error that triggers the recovery flow
    upsets the hardware, hangs TX, and the dev watchdog then calls
    e1000_tx_timeout() -> schedule_work(&adapter->reset_task): the
    async opponent is generated by the same event chain that starts
    the recovery.  This makes the ER context the most reachable of
    the two.
* Consequences
  reset_task holds RTNL forever: every later rtnl_lock() user (all
  network configuration, most ethtool/netlink operations) queues
  forever.  The recovery thread never returns: in the PM context
  device_resume() does not complete (system wakeup hangs -- in my
  run the host's wakeup poke was ineffective because the guest was
  stuck mid-resume, not asleep); in the ER context the recovery
  flow wedges and the device stays offline.  hung-task / soft-lockup
  reports follow; only a reboot recovers.  No memory-safety issue:
  all objects stay alive; this is a pure liveness bug.
* Evidence (pristine kernel, timing-only instrument; module attached)
  e1000race.c is a kprobe module: it parks the resume thread at the
  gate point (kprobe on napi_enable filtered by the return address
  of the call inside e1000_up -- widening the natural >=10 ms window
  to 5 s), schedules a real ndo_tx_timeout via a delayed work (the
  exact indirect call dev_watchdog would make; QEMU's e1000 model
  completes TX immediately so a real watchdog TX hang is not
  reachable in the VM), and logs both napi_disable entries and
  reset_task executions.  Observed on the S3/resume path (serial
  console, timestamps compressed):
    [56.468] napi_disable entered by kworker/u16:4      <- shutdown
              side (__e1000_shutdown -> e1000_down); NAPI still
              enabled, returns normally; leaves SCHED=1
    [56.42-58.22]   S3: freeze, CPUs off, ACPI low-level resume, CPUs on
    [58.267] resume thread (kworker/u16:3) parked 5000 ms before
              napi_enable; clear_bit(__E1000_DOWN) already executed
    [58.323] trigger: invoking eth0->ndo_tx_timeout -> schedules
              e1000_reset_task inside the resume window
    [58.336] reset_task execution #1
    [58.343] e1000 0000:00:02.0 eth0: Reset adapter      <- driver log
    [58.360] napi_disable entered by kworker/1:1        <- reset_task
              parks here holding netdev_lock + RTNL
    [63.283] resume stall done; napi_enable now contends netdev_lock
    (silence: no "PM: suspend exit", no "Restarting tasks";
     `ip link set eth0 down` queued forever; host wakeup ineffective;
     the VM had to be killed by timeout)
  Both sides of the mutual wait were thus observed directly.  The
  in-VM probes also dumped the RTNL waiter's kernel stack
  (rtnl_lock wait) and the D-state kworker.  Negative control:
  identical kernel, no window widening, three full link-churn +
  S3/resume cycles -- all three resumed, an RTNL probe returned
  instantly, zero splats and zero hung tasks (the natural window is
  the >=10 ms preemption; short cycles do not hit it, matching the
  analysis).
  Instrument usage (attached e1000race.c; needs a kernel with
  CONFIG_E1000=y and KPROBES; the ra-offset parameter
  napi_ret_off=0x38 matches my KASAN build and is recomputable for
  other builds):
    make -C <kernel-build-dir> M=$PWD modules
    # in the guest:
    insmod e1000race.ko stall_napi_ms=5000
    ip link set eth0 up; ip addr add 10.0.2.15/24 dev eth0
    echo 1 > /sys/module/e1000race/parameters/armed
    echo 0  > /sys/class/rtc/rtc0/wakealarm
    echo +6 > /sys/class/rtc/rtc0/wakealarm
    echo mem > /sys/power/state
    # after the RTC wake: the timeline above; resume never completes.


Regards,
Hanxiang Xu
xuhx@hust.edu.cn



[-- Attachment #2: Makefile --]
[-- Type: application/octet-stream, Size: 21 bytes --]

obj-m += e1000race.o

[-- Attachment #3: e1000race.c --]
[-- Type: text/plain, Size: 8208 bytes --]

// SPDX-License-Identifier: GPL-2.0
/*
 * e1000race.c - controlled-window instrument for report defect 2
 * (e1000_resume()/e1000_io_resume() bring the device back up without
 * RTNL; an e1000_reset_task running inside the resume window deadlocks
 * with the resume thread on the NAPI state machine:
 *   reset_task: e1000_down -> napi_disable parks holding netdev_lock+RTNL
 *              waiting for NAPI_STATE_SCHED to clear,
 *   resume    : napi_enable (the only SCHED clearer) blocks on netdev_lock
 *   -> mutual wait, RTNL never released, system-wide network hang).
 *
 * Zero kernel source modification. One kprobe + one delayed-work trigger:
 *
 *  probe @ napi_enable entry, filtered by return address (the call site
 *  inside e1000_up): when armed (after S3 has happened), this is exactly
 *  the resume thread sitting BETWEEN clear_bit(__E1000_DOWN) and
 *  napi_enable - the defect-2 opening point. The handler then
 *    (a) schedules a second ndo_tx_timeout invocation, i.e. puts a real
 *        reset_task to run inside the (now widened) resume window - the
 *        natural precondition of defect 2 (work surviving across S3 / the
 *        AER-same-source scheduling of the report's context B), and
 *    (b) parks the resume thread for stall_napi_ms (busy wait: msleep is
 *        illegal under kprobes) - widening the two-adjacent-statements
 *        window that a >=10ms preemption would hit naturally.
 *
 * QEMU's e1000 model completes TX immediately, so real TX hangs (what
 * makes dev_watchdog call ndo_tx_timeout) never occur naturally here;
 * the delayed work stands in the dev-core watchdog's place and performs
 * the exact same indirect call on the netdev.
 *
 * Expected outcome: reset_task parks in napi_disable holding
 * netdev_lock+RTNL; the parked resume thread wakes into napi_enable and
 * blocks on the same netdev_lock -> deadlock; every later rtnl_lock()
 * user (e.g. `ip link set eth0 down`) hangs.
 */
#define pr_fmt(fmt) "E1000RACE: " fmt

#include <linux/module.h>
#include <linux/init.h>
#include <linux/kernel.h>
#include <linux/kprobes.h>
#include <linux/delay.h>
#include <linux/atomic.h>
#include <linux/sched/clock.h>
#include <linux/netdevice.h>
#include <linux/inet.h>

static int stall_napi_ms = 5000;
module_param(stall_napi_ms, int, 0600);
MODULE_PARM_DESC(stall_napi_ms, "park the resume thread before napi_enable for this long");

/*
 * offset of the napi_enable call site's return address, relative to the
 * address kprobes reports for e1000_up (kallsyms symbol + 4, ENDBR):
 * build-kasan-7.3: e1000_up @ +0, call napi_enable @ +0x37 (5 bytes) ->
 * return address @ +0x3c from the symbol -> +0x38 from the probe address.
 */
static ulong napi_ret_off = 0x38;
module_param(napi_ret_off, ulong, 0600);
MODULE_PARM_DESC(napi_ret_off, "ra offset of the napi_enable call inside e1000_up, relative to kprobe-reported symbol address (build-kasan-7.3: 0x38)");

static int armed;
module_param(armed, int, 0600);
MODULE_PARM_DESC(armed, "0: ignore e1000_up napi_enable hits (e.g. from e1000_open); 1: this is the resume hit");

static char *netif_name = "eth0";
module_param(netif_name, charp, 0600);

static unsigned long e1000_up_addr;

static atomic_t resume_hits = ATOMIC_INIT(0);
static atomic_t reset_seen = ATOMIC_INIT(0);
static atomic_t near_dbg = ATOMIC_INIT(0);

static u64 mono_ns(void)
{
	return ktime_get_mono_fast_ns();
}

static void park_ms(unsigned long ms)
{
	u64 t0 = mono_ns();
	u64 dur = (u64)ms * 1000000ULL;

	while ((s64)(mono_ns() - t0) < (s64)dur)
		cpu_relax();
}

/* dev-core watchdog stand-in: performs the exact indirect call the core
 * would make on a real TX hang; e1000_tx_timeout then schedules the real
 * reset_task via schedule_work(). Safe from any context. */
static void trigger_tx_timeout(struct work_struct *w)
{
	struct net_device *dev = dev_get_by_name(&init_net, netif_name);

	if (!dev) {
		pr_err("trigger: netdev %s not found\n", netif_name);
		return;
	}
	if (!dev->netdev_ops || !dev->netdev_ops->ndo_tx_timeout) {
		pr_err("trigger: %s has no ndo_tx_timeout\n", netif_name);
		dev_put(dev);
		return;
	}
	pr_warn("trigger: invoking %s->ndo_tx_timeout -> schedules e1000_reset_task inside the resume window\n",
		netif_name);
	dev->netdev_ops->ndo_tx_timeout(dev, 0);
	dev_put(dev);
}

static DECLARE_DELAYED_WORK(trigger_work, trigger_tx_timeout);

static int napi_enable_pre(struct kprobe *p, struct pt_regs *regs)
{
	unsigned long ra = *(unsigned long *)regs->sp;

	if (ra != e1000_up_addr + napi_ret_off) {
		/* near-caller debug: print any ra that lands inside e1000_up */
		if (ra > e1000_up_addr - 0x10 && ra < e1000_up_addr + 0x200 &&
		    atomic_inc_return(&near_dbg) <= 8)
			pr_info("near-caller ra=%lx (probe-addr off +0x%lx)\n",
				ra, ra - e1000_up_addr);
		return 0;
	}

	if (!armed) {
		pr_info("napi_enable from e1000_up seen while disarmed (open path?) - ignored\n");
		return 0;
	}
	if (atomic_xchg(&resume_hits, 1))
		return 0;	/* only the first resume hit is instrumented */

	/* (a) put a real reset_task into the widened resume window.
	 * Must run on another CPU while this one is parked: the probe context
	 * has preemption disabled, so queue on the unbound pool. */
	queue_delayed_work(system_unbound_wq, &trigger_work, msecs_to_jiffies(50));

	/* (b) park the resume thread between clear_bit(DOWN) and napi_enable */
	pr_warn("resume thread (pid %d, %s) parked %d ms before napi_enable; clear_bit(__E1000_DOWN) already executed\n",
		current->pid, current->comm, stall_napi_ms);
	park_ms(stall_napi_ms);
	pr_warn("resume stall done; napi_enable now contends netdev_lock (expected: held by reset_task's napi_disable)\n");
	return 0;
}

/* observation-only probe: log every reset_task execution */
static int reset_task_pre(struct kprobe *p, struct pt_regs *regs)
{
	int n = atomic_inc_return(&reset_seen);

	pr_warn("reset_task execution #%d (work=%p)\n", n, (void *)regs->di);
	return 0;
}

/* observation-only probe: log who enters napi_disable (the defect-2
 * parking point: reset_task enters it holding netdev_lock+RTNL and never
 * returns while SCHED stays set) */
static int napi_disable_pre(struct kprobe *p, struct pt_regs *regs)
{
	if (current->flags & PF_WQ_WORKER)
		pr_warn("napi_disable entered by %s (pid %d) - if this is reset_task it now parks here holding netdev_lock+RTNL\n",
			current->comm, current->pid);
	return 0;
}

static struct kprobe kp_reset = {
	.symbol_name = "e1000_reset_task",
	.pre_handler = reset_task_pre,
};

static struct kprobe kp_ndis = {
	.symbol_name = "napi_disable",
	.pre_handler = napi_disable_pre,
};

static struct kprobe kp_napi = {
	.symbol_name = "napi_enable",
	.pre_handler = napi_enable_pre,
};

static unsigned long sym_addr(const char *name)
{
	struct kprobe probe = { .symbol_name = name, };
	unsigned long addr = 0;

	if (register_kprobe(&probe) == 0) {
		addr = (unsigned long)probe.addr;
		unregister_kprobe(&probe);
	}
	return addr;
}

static int __init e1000race_init(void)
{
	int ret;

	e1000_up_addr = sym_addr("e1000_up");
	if (!e1000_up_addr) {
		pr_err("cannot resolve e1000_up\n");
		return -EINVAL;
	}
	ret = register_kprobe(&kp_reset);
	if (ret) {
		pr_err("register kp_reset failed: %d\n", ret);
		return ret;
	}
	ret = register_kprobe(&kp_ndis);
	if (ret) {
		unregister_kprobe(&kp_reset);
		pr_err("register kp_ndis failed: %d\n", ret);
		return ret;
	}
	ret = register_kprobe(&kp_napi);
	if (ret) {
		unregister_kprobe(&kp_ndis);
		unregister_kprobe(&kp_reset);
		pr_err("register kp_napi failed: %d\n", ret);
		return ret;
	}
	pr_info("armed-probe installed: e1000_up(kprobe addr)=%lx (+0x%lx -> ra of napi_enable call), e1000_reset_task=%lx\n",
		e1000_up_addr, napi_ret_off, (unsigned long)kp_reset.addr);
	pr_info("module loaded disarmed; write 1 to /sys/module/e1000race/parameters/armed right before S3\n");
	return 0;
}

static void __exit e1000race_exit(void)
{
	cancel_delayed_work_sync(&trigger_work);
	unregister_kprobe(&kp_napi);
	unregister_kprobe(&kp_ndis);
	unregister_kprobe(&kp_reset);
	pr_info("disarmed\n");
}

module_init(e1000race_init);
module_exit(e1000race_exit);
MODULE_LICENSE("GPL");
MODULE_DESCRIPTION("e1000 defect-2 controlled-window deadlock instrument");