Intermittent kernel WARN in mm.h get_page() when forcefully removing a xen_netfront interface from xenstore

[Aaron Rainbolt <arraybolt3@gmail.com>]

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

A user in the Qubes OS issue tracker reported that they could cause
kernel WARNs in some of their AppVMs when forcibly terminating a NetVM
that those AppVMs were connected to. [1] Typically, a message such as
`vif vif-0: xenbus: device forcefully removed from xenstore` appears,
then a "WARNING" appears immediately thereafter indicating an issue in
`xennet_disconnect_backend`, with the line of code throwing the warning
being somewhere in `include/linux/mm.h`. Originally it was thought that
the warning was simply normal behavior when a device is forcefully
removed, but it seemed very weird that memory management code would be
in charge of triggering that warning. Furthermore, I cannot reproduce
the issue reliably; for some users, it happens immediately after
shutting down the NetVM, whereas for me, I had to use multiple tricks
including pausing and unpausing a VM to trigger it. After some
fiddling, I was able to reproduce the issue using the latest stable
7.1.3 kernel:

1. On a Whonix-Workstation 18 AppVM (such as anon-whonix), build kernel
   7.1.3 using the steps from
   https://kernel-team.pages.debian.net/kernel-handbook/ch-common-tasks.html#s-common-size,
   ensuring that debug info is enabled. Use Debian's kernel config from
   the linux-base-7.1.3+deb14-amd64_7.1.3-1_amd64.deb package as the
   starting kernel config.
2. Install the new kernel into a cloned Whonix-Workstation 18 template.
3. Install pvgrub in dom0: `sudo qubes-dom0-update --action=install
   grub2-xen-pvh`
4. Create a new AppVM named `anon-whonix-kerntest` based on this
   template.
5. Set the kernel for `anon-whonix-kerntest` to `pvgrub2-pvh`.
6. Start `anon-whonix-kerntest`.
7. Run `uname -r` in `anon-whonix-kerntest`, ensure that the kernel
   version displayed is 7.1.3.
8. Open a root QTerminal window in `anon-whonix-kerntest` by running
   the following in dom0: `qvm-run -u root anon-whonix-kerntest
   qterminal`.
9. In the root QTerminal window, run `sysctl kernel.warn_limit=5` to
   prevent an immediate kernel panic when the kernel warn occurs.
10. Open Tor Browser in `anon-whonix-kerntest`, and attempt to navigate
    to a fairly resource-intensive web page like Reddit's front page.
11. While the page is still loading, run `qvm-pause
    anon-whonix-kerntest` in dom0 to freeze the AppVM.
12. In dom0, run `qvm-kill sys-whonix`.
13. Wait a few seconds, then run `qvm-unpause anon-whonix-kerntest` to
    unfreeze the AppVM.
14. In the root QTerminal window of `anon-whonix-kerntest`, run `dmesg
    -w` to watch for kernel messages.
15. Wait a few seconds, then start `sys-whonix`. Qubes OS will reattach
    the network when this is done (there is the equivalent of `xl
    network-attach` done by the Qubes code automatically). The following
    messages should appear in dmesg:

    [  426.609004] vif vif-0: xenbus: device forcefully removed from xenstore
    [  426.609242] ------------[ cut here ]------------
    [  426.609254] WARNING: ./include/linux/mm.h:2097 at xennet_disconnect_backend+0x1c7/0x520 [xen_netfront], CPU#0: xenwatch/64
    [  426.609269] Modules linked in: snd_seq_dummy(E) snd_hrtimer(E) snd_seq(E) snd_seq_device(E) snd_timer(E) snd(E) soundcore(E) cfg80211(E) nls_ascii(E) nls_cp437(E) vfat(E) fat(E) rfkill(E) xenfs(E) nft_reject_inet(E) nf_reject_ipv4(E) nf_reject_ipv6(E) nft_reject(E) nft_ct(E) nf_conntrack(E) nf_defrag_ipv6(E) nf_defrag_ipv4(E) nf_tables(E) binfmt_misc(E) intel_rapl_msr(E) intel_rapl_common(E) intel_uncore_frequency_common(E) intel_pmc_ssram_telemetry(E) intel_vsec(E) aesni_intel(E) gf128mul(E) xen_netfront(E) xen_privcmd(E) xen_gntdev(E) xen_gntalloc(E) xen_blkback(E) drm(E) xen_evtchn(E) jitterentropy_rng(E) libsha3(E) loop(E) configfs(E) efi_pstore(E) nfnetlink(E) ip_tables(E) x_tables(E) autofs4(E) ext4(E) crc16(E) mbcache(E) jbd2(E) dm_snapshot(E) dm_bufio(E) dm_mod(E) xen_blkfront(E)    
    [  426.609334] CPU: 0 UID: 0 PID: 64 Comm: xenwatch Tainted: G            E       7.1.3 #5 PREEMPT(lazy)
    [  426.609340] Tainted: [E]=UNSIGNED_MODULE
    [  426.609343] RIP: 0010:xennet_disconnect_backend+0x1c7/0x520 [xen_netfront]
    [  426.609349] Code: 94 dd a0 10 00 00 48 8b 4a 08 48 89 ce 83 e6 01 48 83 ee 01 48 09 f1 48 21 ca 0f b6 4a 33 81 f9 f5 00 00 00 0f 85 ea fe ff ff <0f> 0b 49 81 ff 00 01 00 00 0f 82 f8 fe ff ff 4c 89 fe 48 c7 c7 e0    
    [  426.609352] RSP: 0018:ffffce3d810c3c98 EFLAGS: 00010246
    [  426.609356] RAX: 0000000000000010 RBX: 0000000000000000 RCX: 00000000000000f5
    [  426.609358] RDX: fffffb0d80ca9800 RSI: 0000000000000000 RDI: ffffffff88c8a8a0
    [  426.609360] RBP: ffff8dec51df0000 R08: ffff8debf4dd5a80 R09: ffff8debf4dd5a80
    [  426.609362] R10: 0000000000000020 R11: 00000000000000bf R12: 0000000000000000
    [  426.609364] R13: ffff8dec8ef30b80 R14: ffff8dec197fcac0 R15: 0000000000000000
    [  426.609366] FS:  0000000000000000(0000) GS:ffff8ded2d129000(0000) knlGS:0000000000000000
    [  426.609369] CS:  0010 DS: 0000 ES: 0000 CR0: 0000000080050033
    [  426.609370] CR2: 00005faa1a7d3737 CR3: 00000000b420a003 CR4: 0000000000770ef0
    [  426.609377] PKRU: 55555554
    [  426.609379] Call Trace:
    [  426.609384]  <TASK>
    [  426.609395]  xennet_remove+0x9f/0x380 [xen_netfront]
    [  426.609399]  ? kfree+0x26e/0x3d0
    [  426.609407]  xenbus_dev_remove+0x71/0x100
    [  426.609414]  device_release_driver_internal+0x19c/0x200
    [  426.609419]  bus_remove_device+0xe8/0x1c0
    [  426.609425]  ? device_remove_attrs+0xa1/0x100
    [  426.609430]  device_del+0x160/0x3e0
    [  426.609433]  ? __pfx_xenwatch_thread+0x10/0x10
    [  426.609436]  device_unregister+0x17/0x70
    [  426.609439]  xenbus_dev_changed.cold+0x3e/0x5b
    [  426.609445]  ? __pfx_xenwatch_thread+0x10/0x10
    [  426.609447]  xenwatch_thread+0x92/0x1c0
    [  426.609451]  ? __pfx_autoremove_wake_function+0x10/0x10
    [  426.609466]  kthread+0xe3/0x120
    [  426.609470]  ? __pfx_kthread+0x10/0x10
    [  426.609473]  ret_from_fork+0x2ba/0x340
    [  426.609478]  ? __pfx_kthread+0x10/0x10
    [  426.609480]  ret_from_fork_asm+0x1a/0x30
    [  426.609491]  </TASK>
    [  426.609493] ---[ end trace 0000000000000000 ]---

(Note that I have not been able to reproduce the issue reliably; these
steps worked for me once, but they may not work every time.)

`./include/linux/mm.h:2097` looks like this:

```
static inline void get_page(struct page *page)
{
	struct folio *folio = page_folio(page);
	if (WARN_ON_ONCE(folio_test_slab(folio))) /* <-- 2097 */
		return;
	if (WARN_ON_ONCE(folio_test_large_kmalloc(folio)))
		return;
	folio_get(folio);
}
```

Following the stack trace, all of these line numbers should be accurate
if working with an unmodified 7.1.3 kernel tree:

    $ scripts/faddr2line ./drivers/net/xen-netfront.ko xennet_disconnect_backend+0x1c7/0x520
    xennet_disconnect_backend+0x1c7/0x520:
    get_page at /home/user/linux-7.1.3/./include/linux/mm.h:2097 (discriminator 1)
    (inlined by) xennet_release_tx_bufs at /home/user/linux-7.1.3/drivers/net/xen-netfront.c:1435 (discriminator 1)
    (inlined by) xennet_disconnect_backend at /home/user/linux-7.1.3/drivers/net/xen-netfront.c:1839 (discriminator 1)

    $ scripts/faddr2line ./drivers/net/xen-netfront.ko xennet_remove+0x9f/0x380 
    xennet_remove+0x9f/0x380:
    xennet_remove at /home/user/linux-7.1.3/drivers/net/xen-netfront.c:2664

    $ scripts/faddr2line ./vmlinux kfree+0x26e/0x3d0                            
    kfree+0x26e/0x3d0:
    stat at mm/slub.c:383
    (inlined by) slab_free at mm/slub.c:6258
    (inlined by) kfree at mm/slub.c:6566

    $ scripts/faddr2line ./vmlinux xenbus_dev_remove+0x71/0x100
    xenbus_dev_remove+0x71/0x100:
    xenbus_dev_remove at drivers/xen/xenbus/xenbus_probe.c:353

    $ scripts/faddr2line ./vmlinux device_release_driver_internal+0x19c/0x200
    device_release_driver_internal+0x19c/0x200:
    __device_release_driver at drivers/base/dd.c:1354
    (inlined by) device_release_driver_internal at drivers/base/dd.c:1375

    $ scripts/faddr2line ./vmlinux bus_remove_device+0xe8/0x1c0          
    bus_remove_device+0xe8/0x1c0:
    kset_put at include/linux/kobject.h:193
    (inlined by) subsys_put at drivers/base/base.h:74
    (inlined by) bus_remove_device at drivers/base/bus.c:671

    $ scripts/faddr2line ./vmlinux device_remove_attrs+0xa1/0x100        
    device_remove_attrs+0xa1/0x100:
    device_remove_attrs at drivers/base/core.c:2976

    $ scripts/faddr2line ./vmlinux device_del+0x160/0x3e0    
    device_del+0x160/0x3e0:
    device_del at drivers/base/core.c:3896

    $ scripts/faddr2line ./vmlinux __pfx_xenwatch_thread+0x10/0x10                  
    __pfx_xenwatch_thread+0x10/0x10:
    xenwatch_thread at drivers/xen/xenbus/xenbus_xs.c:844

    $ scripts/faddr2line ./vmlinux device_unregister+0x17/0x70                           
    device_unregister+0x17/0x70:
    put_device at drivers/base/core.c:3813
    (inlined by) device_unregister at drivers/base/core.c:3937

    $ scripts/faddr2line ./vmlinux xenbus_dev_changed.cold+0x3e/0x5b                       
    xenbus_dev_changed.cold+0x3e/0x5b:
    xenbus_cleanup_devices at drivers/xen/xenbus/xenbus_probe.c:451
    (inlined by) xenbus_dev_changed at drivers/xen/xenbus/xenbus_probe.c:648

    $ scripts/faddr2line ./vmlinux __pfx_xenwatch_thread+0x10/0x10                            
    __pfx_xenwatch_thread+0x10/0x10:
    xenwatch_thread at drivers/xen/xenbus/xenbus_xs.c:844

    $ scripts/faddr2line ./vmlinux xenwatch_thread+0x92/0x1c0                           
    xenwatch_thread+0x92/0x1c0:
    xenwatch_thread at drivers/xen/xenbus/xenbus_xs.c:870

    $ scripts/faddr2line ./vmlinux __pfx_autoremove_wake_function+0x10/0x10                      
    __pfx_autoremove_wake_function+0x10/0x10:
    autoremove_wake_function at kernel/sched/wait.c:402

    $ scripts/faddr2line ./vmlinux kthread+0xe3/0x120                            
    kthread+0xe3/0x120:
    kthread at kernel/kthread.c:436

    $ scripts/faddr2line ./vmlinux __pfx_kthread+0x10/0x10              
    __pfx_kthread+0x10/0x10:
    kthread at kernel/kthread.c:381

    $ scripts/faddr2line ./vmlinux ret_from_fork+0x2ba/0x340                   
    ret_from_fork+0x2ba/0x340:
    ret_from_fork at arch/x86/kernel/process.c:164

    $ scripts/faddr2line ./vmlinux __pfx_kthread+0x10/0x10
    __pfx_kthread+0x10/0x10:
    kthread at kernel/kthread.c:381

    $ scripts/faddr2line ./vmlinux ret_from_fork_asm+0x1a/0x30                   
    ret_from_fork_asm+0x1a/0x30:
    ret_from_fork_asm at arch/x86/entry/entry_64.S:255

--
Aaron

[1] https://github.com/QubesOS/qubes-issues/issues/10969

[-- Attachment #2: OpenPGP digital signature --]
[-- Type: application/pgp-signature, Size: 228 bytes --]