panic: vtnet_txq_offload when suricata reloads

[aleks...@gmail.com]

Ciao,

Possibly this is not the right place for such report, but I have encountered one small problem with HardenedBSD 12 and suricata.

Here is a log file:

Mar 31 23:28:39 nixd pkg-static[8342]: suricata-4.1.3 deinstalled
Mar 31 23:28:40 nixd pkg-static[12711]: suricata-4.1.3 installed
Mar 31 23:30:18 nixd suricata[76287]: [100437] <Notice> -- Signal Received.  Stopping engine.
Mar 31 23:30:19 nixd suricata[76287]: [100866] <Error> -- [ERRCODE: SC_ERR_PCAP_DISPATCH(20)] - error code -2
Mar 31 23:30:28 nixd suricata[76287]: [100437] <Notice> -- Stats for 'vtnet0':  pkts: 5580966, drop: 139630 (2.50%), invalid chksum: 0
Mar 31 23:30:28 nixd suricata[51306]: [101015] <Notice> -- This is Suricata version 4.1.3 RELEASE
Mar 31 23:30:29 nixd barnyard2[9025]: Closing spool file '/var/log/suricata/unified2.alert.1552251664'. Read 41 records
Mar 31 23:30:29 nixd barnyard2[9025]: Opened spool file '/var/log/suricata/unified2.alert.1554067829'
Mar 31 23:30:29 nixd barnyard2[9025]: Waiting for new data
Mar 31 23:34:38 nixd syslogd: kernel boot file is /boot/kernel/kernel
Mar 31 23:34:38 nixd kernel: [4401732] panic: vtnet_txq_offload: mbuf 0xfffff80179254500 TSO without checksum offload 0x1010
Mar 31 23:34:38 nixd kernel: [4401732] cpuid = 3
Mar 31 23:34:38 nixd kernel: [4401732] time = 1554067834
Mar 31 23:34:38 nixd kernel: [4401732] __HardenedBSD_version = 1200058 __FreeBSD_version = 1200502
Mar 31 23:34:38 nixd kernel: [4401732] version = FreeBSD 12.0-STABLE-HBSD  HARDENEDBSD-12-STABLE
Mar 31 23:34:38 nixd kernel: [4401732] KDB: stack backtrace:
Mar 31 23:34:38 nixd kernel: [4401732] #0 0xffffffff80b2006d at kdb_backtrace+0x6d
Mar 31 23:34:38 nixd kernel: [4401732] #1 0xffffffff80ad9a28 at vpanic+0x1a8
Mar 31 23:34:38 nixd kernel: [4401732] #2 0xffffffff80ad9803 at panic+0x43
Mar 31 23:34:38 nixd kernel: [4401732] #3 0xffffffff80931c60 at vtnet_txq_mq_start_locked+0x680
Mar 31 23:34:38 nixd kernel: [4401732] #4 0xffffffff809325d0 at vtnet_txq_mq_start+0x70
Mar 31 23:34:38 nixd kernel: [4401732] #5 0xffffffff80bd173a at ether_output_frame+0xba
Mar 31 23:34:38 nixd kernel: [4401732] #6 0xffffffff80bd15ef at ether_output+0x69f
Mar 31 23:34:38 nixd kernel: [4401732] #7 0xffffffff80c605a5 at ip_output+0x1475
Mar 31 23:34:38 nixd kernel: [4401732] #8 0xffffffff80ce0542 at tcp_output+0x1a62
Mar 31 23:34:38 nixd kernel: [4401732] #9 0xffffffff80cf2596 at tcp_usr_send+0x406
Mar 31 23:34:38 nixd kernel: [4401732] #10 0xffffffff80b67d49 at sosend_generic+0x459
Mar 31 23:34:38 nixd kernel: [4401732] #11 0xffffffff80b67f93 at sosend+0x73
Mar 31 23:34:38 nixd kernel: [4401732] #12 0xffffffff80b46432 at soo_write+0x42
Mar 31 23:34:38 nixd kernel: [4401732] #13 0xffffffff80b3dfdd at dofilewrite+0x9d
Mar 31 23:34:38 nixd kernel: [4401732] #14 0xffffffff80b3dc9a at kern_writev+0x4a
Mar 31 23:34:38 nixd kernel: [4401732] #15 0xffffffff80b3dc46 at sys_write+0x86
Mar 31 23:34:38 nixd kernel: [4401732] #16 0xffffffff80f9b8b0 at amd64_syscall+0x270
Mar 31 23:34:38 nixd kernel: [4401732] #17 0xffffffff80f7596d at fast_syscall_common+0x101
Mar 31 23:34:38 nixd kernel: [4401732] Uptime: 50d22h42m12s
Mar 31 23:34:38 nixd kernel: [4401732] Automatic reboot in 15 seconds - press a key on the console to abort
Mar 31 23:34:38 nixd kernel: [4401732] Rebooting...
Mar 31 23:34:38 nixd kernel: [4401732] cpu_reset: Restarting BSP
Mar 31 23:34:38 nixd kernel: [4401732] cpu_reset_proxy: Stopped CPU 3

Unfortunatelly, I don't have crashdump.  dumpdev="AUTO" but still no crashdump was found in the /var/crash

Each time when suricata is restarted it is crashing the whole system.

Below is the list of the kernel modules loaded:

root@nixd:/usr/home/admin1991 # kldstat
Id Refs Address                Size Name
 1   38                0x0  2224338 kernel
 2    1                0x0   450960 zfs.ko
 3    2                0x0     a850 opensolaris.ko
 4    1                0x0     2498 intpm.ko
 5    1                0x0      a70 smbus.ko
 6    1                0x0     1860 uhid.ko
 7    1                0x0     1b40 wmt.ko
 8    1                0x0     4b30 evdev.ko
 9    1                0x0      9d3 pflog.ko
10    1                0x0    33200 pf.ko
11    1                0x0     77a0 secadm.ko
12    1                0x0      aef mac_ntpd.ko
13    1                0x0     2720 nullfs.ko
14    1                0x0      96a sndboxif.ko
15    1                0x0     cee0 sandbox.ko

[Shawn Webb]

Hey,

It appears you're running Suricata in netmap (IPS) mode, correct? If
so, you'll need to disable all hardware offloading for the NIC(s) it's
listening on.

OPNsense has some good documentation for running Suricata in IPS mode.

Thanks,

--
Shawn Webb
Cofounder / Security Engineer
HardenedBSD

Tor-ified Signal: +1 443-546-8752
Tor+XMPP+OTR: lat...@is.a.hacker.sx
GPG Key ID: 0xFF2E67A277F8E1FA
GPG Key Fingerprint: D206 BB45 15E0 9C49 0CF9 3633 C85B 0AF8 AB23 0FB2

[Franco Fichtner]

Hi,

vtnet support for netmap is still relatively young and might still have
bugs so it's worth reporting this to FreeBSD with a stack trace.

I'm CC'ing Murat who helped with the vtnet inclusion in FreeBSD. Maybe
he has some additional context or can help with reaching the right
people.


Cheers,
Franco

[Murat Balaban]

Hi Franco,

Thanks for having me in the conversation.

Hi there, 

As Franco wrote, it looks like we need a bit more cooperation with the netmap team to make the current netmap code super stable in 11/12-STABLE. 

In the meantime, I'd be happy if you can submit a PR over here:

https://github.com/luigirizzo/netmap/issues

--

Best,

Murat

W: https://sunnyvalley.io

[aleks...@gmail.com]

Hello Shawn,

Thank you for your reply.

Yes that is right - suricata is working in the IPS mode. I don't remember if such behaviour was observed when server was running HBSD11 kernel.

if (flags & CSUM_TSO) {
        if (__predict_false(proto != IPPROTO_TCP)) {
            /* Likely failed to correctly parse the mbuf. */
            sc->vtnet_stats.tx_tso_not_tcp++;
            goto drop;
        }

        KASSERT(hdr->flags & VIRTIO_NET_HDR_F_NEEDS_CSUM,
            ("%s: mbuf %p TSO without checksum offload %#x",
            __func__, m, flags));

        error = vtnet_txq_offload_tso(txq, m, etype, csum_start, hdr);
        if (error)
            goto drop;
}

The panic happens at the KASSERT at sys/dev/virtio/network/if_vtnet.c(2140). I reproduced the crash on the VM with HBSD12 kernel.  I will setup HBSD11 VM guest tomorrow and try to test suricata there.

Problem happens only when Suricata is restarted, when service suricata restart is executed.

вторник, 23 апреля 2019 г., 1:00:16 UTC+2 пользователь Shawn Webb написал:

[aleks...@gmail.com]

Hello Franco,

I got it, I will report problem to the FBSD developers, but before I need to reproduce the crash on FreeBSD 12 just in case.

--

Cordiali saluti,

Frisk

вторник, 23 апреля 2019 г., 7:21:38 UTC+2 пользователь Franco Fichtner написал:

Hi,

vtnet support for netmap is still relatively young and might still have
bugs so it's worth reporting this to FreeBSD with a stack trace.

I'm CC'ing Murat who helped with the vtnet inclusion in FreeBSD.  Maybe
he has some additional context or can help with reaching the right
people.


Cheers,
Franco

[aleks...@gmail.com]

Hello,

I have some news about kernel panic:

1) The suricata was captured packets not in netmap mode but in pcap mode suricata -D --pcap=vtnet0 . When running in netmap capturing mode the network traffic is not passed in or out.

2) I was not able to reproduce the problem on the FreeBSD 12 RELEASE.

FreeBSD freebsd 12.0-RELEASE-p3 FreeBSD 12.0-RELEASE-p3 GENERIC  amd64

3) It is hard to reproduce the problem. In the wild it happens just when I reload suricata. On the HardenedBSD 12-STABLE in order to reproduce the crash (artificially) it is required to: start the suricata in the pcap capturing mode. Then as soon as it loads and starts capturing, execute service suricata onestop and immediately start typing command top and execute it. All commands should be typed in ssh terminal.

FreeBSD hdbsd 12.0-STABLE-HBSD FreeBSD 12.0-STABLE-HBSD #1  eed2cf06624(hardened/12-stable/master)-dirty: Wed Apr 24 03:30:43 CEST 2019     root@hdbsd:/usr/obj/usr/src/amd64.amd64/sys/HARDENEDBSD  amd64

On both kernels suricata (when stopped) outputs the following message:

Apr 25 02:08:59 freebsd suricata[61799]: [100130] <Error> -- [ERRCODE: SC_ERR_PCAP_DISPATCH(20)] - error code -2

4) If someone would like to analyze the crashdump I can upload crashdump and kernel somewhere. Or I can share the qemu VM image of the OS, but I am sure that the kernel binaries would be enough.

If needed below I have attached the dmesg:

[171] panic: vtnet_txq_offload: mbuf 0xfffff80003c0a600 TSO without checksum offload 0x1010
[171] cpuid = 1
[171] time = 1556150586
[171] __HardenedBSD_version = 1200058 __FreeBSD_version = 1200505
[171] version = FreeBSD 12.0-STABLE-HBSD #1  eed2cf06624(hardened/12-stable/master)-dirty: Wed Apr 24 03:30:43 CEST 2019
[171]     root@hdbsd:/usr/obj/usr/src/amd64.amd64/sys/HARDENEDBSD
[171] KDB: stack backtrace:
[171] db_trace_self_wrapper() at db_trace_self_wrapper+0x2b/frame 0xfffffe00005c3290
[171] vpanic() at vpanic+0x1b9/frame 0xfffffe00005c32f0
[171] panic() at panic+0x43/frame 0xfffffe00005c3350
[171] vtnet_txq_mq_start_locked() at vtnet_txq_mq_start_locked+0x64e/frame 0xfffffe00005c33f0
[171] vtnet_txq_mq_start() at vtnet_txq_mq_start+0x70/frame 0xfffffe00005c3430
[171] ether_output_frame() at ether_output_frame+0xba/frame 0xfffffe00005c3460
[171] ether_output() at ether_output+0x69e/frame 0xfffffe00005c3500
[171] ip_output() at ip_output+0x13de/frame 0xfffffe00005c3640
[171] tcp_output() at tcp_output+0x1cb3/frame 0xfffffe00005c3800
[171] tcp_usr_send() at tcp_usr_send+0x35c/frame 0xfffffe00005c38c0
[171] sosend_generic() at sosend_generic+0x44f/frame 0xfffffe00005c3970
[171] sosend() at sosend+0x73/frame 0xfffffe00005c39b0
[171] soo_write() at soo_write+0x42/frame 0xfffffe00005c39e0
[171] dofilewrite() at dofilewrite+0x9d/frame 0xfffffe00005c3a30
[171] kern_writev() at kern_writev+0x4a/frame 0xfffffe00005c3a70
[171] sys_write() at sys_write+0x86/frame 0xfffffe00005c3ac0
[171] amd64_syscall() at amd64_syscall+0x26e/frame 0xfffffe00005c3bf0
[171] fast_syscall_common() at fast_syscall_common+0x101/frame 0xfffffe00005c3bf0
[171] --- syscall (4, FreeBSD ELF64, sys_write), rip = 0x1b2622fb17a, rsp = 0x6bf6d268d378, rbp = 0x6bf6d268d3b0 ---
[171] KDB: enter: panic
---<<BOOT>>---
[1] Copyright (c) 2013-2019 The HardenedBSD Project.
[1] Copyright (c) 1992-2019 The FreeBSD Project.
[1] Copyright (c) 1979, 1980, 1983, 1986, 1988, 1989, 1991, 1992, 1993, 1994
[1]     The Regents of the University of California. All rights reserved.
[1] FreeBSD is a registered trademark of The FreeBSD Foundation.
[1] FreeBSD 12.0-STABLE-HBSD #1  eed2cf06624(hardened/12-stable/master)-dirty: Wed Apr 24 03:30:43 CEST 2019
[1]     root@hdbsd:/usr/obj/usr/src/amd64.amd64/sys/HARDENEDBSD amd64
[1] FreeBSD clang version 7.0.1 (tags/RELEASE_701/final 349250) (based on LLVM 7.0.1)
[1] VT(vga): text 80x25
[1] HardenedBSD: initialize and check features (__HardenedBSD_version 1200058 __FreeBSD_version 1200505).
[1] CPU: AMD Opteron 23xx (Gen 3 Class Opteron) (3210.89-MHz K8-class CPU)
[1]   Origin="AuthenticAMD"  Id=0x100f23  Family=0x10  Model=0x2  Stepping=3
[1]   Features=0x783fbff<FPU,VME,DE,PSE,TSC,MSR,PAE,MCE,CX8,APIC,SEP,MTRR,PGE,MCA,CMOV,PAT,PSE36,MMX,FXSR,SSE,SSE2>
[1]   Features2=0x80a02001<SSE3,CX16,x2APIC,POPCNT,HV>
[1]   AMD Features=0xe6500800<SYSCALL,NX,MMX+,FFXSR,Page1GB,LM,3DNow!+,3DNow!>
[1]   AMD Features2=0x3f3<LAHF,CMP,CR8,ABM,SSE4A,MAS,Prefetch,OSVW>
[1] Hypervisor: Origin = "KVMKVMKVM"
[1] real memory  = 2147483648 (2048 MB)
[1] avail memory = 2039377920 (1944 MB)
[1] Event timer "LAPIC" quality 100
[1] ACPI APIC Table: <BOCHS  BXPCAPIC>
[1] FreeBSD/SMP: Multiprocessor System Detected: 3 CPUs
[1] FreeBSD/SMP: 3 package(s) x 1 core(s)
[1] random: unblocking device.
[1] ioapic0 <Version 1.1> irqs 0-23 on motherboard
[1] Launching APs: 1 2
[1] random: entropy device external interface
[1] [ath_hal] loaded
[1] kbd1 at kbdmux0
[1] module_register_init: MOD_LOAD (vesa, 0xffffffff810cfc40, 0) error 19
[1] 000.000051 [4212] netmap_init               netmap: loaded module
[1] nexus0
[1] vtvga0: <VT VGA driver> on motherboard
[1] cryptosoft0: <software crypto> on motherboard
[1] aesni0: No AES or SHA support.
[1] acpi0: <BOCHS BXPCRSDT> on motherboard
[1] acpi0: Power Button (fixed)
[1] cpu0: <ACPI CPU> on acpi0
[1] atrtc0: <AT realtime clock> port 0x70-0x71,0x72-0x77 irq 8 on acpi0
[1] atrtc0: registered as a time-of-day clock, resolution 1.000000s
[1] Event timer "RTC" frequency 32768 Hz quality 0
[1] Timecounter "ACPI-fast" frequency 3579545 Hz quality 900
[1] acpi_timer0: <24-bit timer at 3.579545MHz> port 0x608-0x60b on acpi0
[1] pcib0: <ACPI Host-PCI bridge> port 0xcf8-0xcff on acpi0
[1] pci0: <ACPI PCI bus> on pcib0
[1] isab0: <PCI-ISA bridge> at device 1.0 on pci0
[1] isa0: <ISA bus> on isab0
[1] atapci0: <Intel PIIX3 WDMA2 controller> port 0x1f0-0x1f7,0x3f6,0x170-0x177,0x376,0xc120-0xc12f at device 1.1 on pci0
[1] ata0: <ATA channel> at channel 0 on atapci0
[1] ata1: <ATA channel> at channel 1 on atapci0
[1] pci0: <bridge> at device 1.3 (no driver attached)
[1] vgapci0: <VGA-compatible display> mem 0xfc000000-0xfdffffff,0xfebd0000-0xfebd0fff at device 2.0 on pci0
[1] vgapci0: Boot video device
[1] virtio_pci0: <VirtIO PCI Network adapter> port 0xc080-0xc09f mem 0xfebd1000-0xfebd1fff,0xfe000000-0xfe003fff irq 11 at device 3.0 on pci0
[1] vtnet0: <VirtIO Networking Adapter> on virtio_pci0
[1] vtnet0: Ethernet address: 52:54:00:b8:f4:ee
[1] vtnet0: netmap queues/slots: TX 1/256, RX 1/128
[1] 000.000760 [ 503] vtnet_netmap_attach       vtnet attached txq=1, txd=256 rxq=1, rxd=128
[1] uhci0: <Intel 82801I (ICH9) USB controller> port 0xc0a0-0xc0bf irq 11 at device 4.0 on pci0
[1] usbus0 on uhci0
[1] usbus0: 12Mbps Full Speed USB v1.0
[1] uhci1: <Intel 82801I (ICH9) USB controller> port 0xc0c0-0xc0df irq 10 at device 4.1 on pci0
[1] usbus1 on uhci1
[1] usbus1: 12Mbps Full Speed USB v1.0
[1] uhci2: <Intel 82801I (ICH9) USB controller> port 0xc0e0-0xc0ff irq 10 at device 4.2 on pci0
[1] usbus2 on uhci2
[1] usbus2: 12Mbps Full Speed USB v1.0
[1] ehci0: <Intel 82801I (ICH9) USB 2.0 controller> mem 0xfebd2000-0xfebd2fff irq 11 at device 4.7 on pci0
[1] usbus3: EHCI version 1.0
[1] usbus3 on ehci0
[1] usbus3: 480Mbps High Speed USB v2.0
[1] virtio_pci1: <VirtIO PCI Console adapter> port 0xc000-0xc03f mem 0xfebd3000-0xfebd3fff,0xfe004000-0xfe007fff irq 10 at device 5.0 on pci0
[1] virtio_pci2: <VirtIO PCI Balloon adapter> port 0xc100-0xc11f mem 0xfe008000-0xfe00bfff irq 11 at device 7.0 on pci0
[1] vtballoon0: <VirtIO Balloon Adapter> on virtio_pci2
[1] virtio_pci3: <VirtIO PCI Block adapter> port 0xc040-0xc07f mem 0xfebd4000-0xfebd4fff,0xfe00c000-0xfe00ffff irq 11 at device 8.0 on pci0
[1] vtblk0: <VirtIO Block Adapter> on virtio_pci3
[1] vtblk0: 10240MB (20971520 512 byte sectors)
[1] acpi_syscontainer0: <System Container> on acpi0
[1] acpi_syscontainer1: <System Container> port 0xaf00-0xaf0b on acpi0
[1] acpi_syscontainer2: <System Container> port 0xafe0-0xafe3 on acpi0
[1] acpi_syscontainer3: <System Container> port 0xae00-0xae13 on acpi0
[1] atkbdc0: <Keyboard controller (i8042)> port 0x60,0x64 irq 1 on acpi0
[1] atkbd0: <AT Keyboard> irq 1 on atkbdc0
[1] kbd0 at atkbd0
[1] atkbd0: [GIANT-LOCKED]
[1] psm0: <PS/2 Mouse> irq 12 on atkbdc0
[1] psm0: [GIANT-LOCKED]
[1] psm0: model IntelliMouse Explorer, device ID 4
[1] fdc0: <floppy drive controller (FDE)> port 0x3f2-0x3f5,0x3f7 irq 6 drq 2 on acpi0
[1] fdc0: does not respond
[1] device_attach: fdc0 attach returned 6
[1] uart0: <16550 or compatible> port 0x3f8-0x3ff irq 4 flags 0x10 on acpi0
[1] uart1: <16550 or compatible> port 0x2f8-0x2ff irq 3 on acpi0
[1] orm0: <ISA Option ROM> at iomem 0xec000-0xeffff pnpid ORM0000 on isa0
[1] vga0: <Generic ISA VGA> at port 0x3c0-0x3df iomem 0xa0000-0xbffff pnpid PNP0900 on isa0
[1] attimer0: <AT timer> at port 0x40 on isa0
[1] Timecounter "i8254" frequency 1193182 Hz quality 0
[1] Event timer "i8254" frequency 1193182 Hz quality 100
[1] fdc0: No FDOUT register!
[1] Timecounters tick every 10.000 msec
[1] ugen3.1: <Intel EHCI root HUB> at usbus3
[1] uhub0: <Intel EHCI root HUB, class 9/0, rev 2.00/1.00, addr 1> on usbus3
[1] ugen2.1: <Intel UHCI root HUB> at usbus2
[1] ugen0.1: <Intel UHCI root HUB> at usbus0
[1] ugen1.1: <Intel UHCI root HUB> at usbus1
[1] uhub1: <Intel UHCI root HUB, class 9/0, rev 1.00/1.00, addr 1> on usbus2
[1] uhub2: <Intel UHCI root HUB, class 9/0, rev 1.00/1.00, addr 1> on usbus0
[1] uhub3: <Intel UHCI root HUB, class 9/0, rev 1.00/1.00, addr 1> on usbus1
[1] cd0 at ata0 bus 0 scbus0 target 0 lun 0
cd0: <QEMU QEMU DVD-ROM 2.5+> Removable CD-ROM SCSI device
cd0: Serial Number QM00001
cd0: 16.700MB/s transfers (WDMA2, ATAPI 12bytes, PIO 65534bytes)
cd0: 330MB (169027 2048 byte sectors)
[1] Trying to mount root from ufs:/dev/vtbd0p2 [rw]...
[1] WARNING: / was not properly dismounted
[1] uhub1: 2 ports with 2 removable, self powered
[1] uhub3: 2 ports with 2 removable, self powered
[1] uhub2: 2 ports with 2 removable, self powered
[2] lo0: link state changed to UP
[2] vtnet0: link state changed to UP
[3] lo1: link state changed to UP
[3] uhub0: 6 ports with 6 removable, self powered
[5] intsmb0: <Intel PIIX4 SMBUS Interface> irq 9 at device 1.3 on pci0
[5] intsmb0: intr IRQ 9 enabled revision 0
[5] smbus0: <System Management Bus> on intsmb0
[6] pflog0: promiscuous mode enabled

--

Cordiali saluti,

Frisk