Random server crashes every few weeks (smp_invltlb: endless loop […] retrysmp_invltlb: ipi sent)

Fri Jul 15 03:54:40 PDT 2016

* Stefan Unterweger on Thu, Jul 07, 2016 at 09:31:47AM +0200:
> > >> Virtio (for block storage devices) could be the cause.  There are known
> > >> bugs in the DragonFly driver for virtio which haven't been tracked down yet
> > >> (not enough of the devs are using virtual hosting to be able to reproduce
> > >> the problem in a debugable way).
> > 
> > Can you try the latest master?  I think it has been fixed there.
> 
> So, the patch is finally in.  At least from the first superficial
> glances, the system now feels more stable than before: a big Synth
> upgrade marathon previously easily got the machine down, yesterday it
> went through.  I’ll have to do a few more stress tests, perhaps on a
> second machine, before I can tick that off.

With the ‚gentle‘ stress tests done so far the system -seems- stable,
but it looks trecherous.  Today I have got another semi-crash under
moderate load; this is the trace that has just appeared in syslog:

| Jul 15 12:44:01 rhaal kernel: Trace beginning at frame 0xffffffe08025d580
| Jul 15 12:44:01 rhaal kernel: smp_invltlb() at smp_invltlb+0x229 0xffffffff80a2d3c1 
| Jul 15 12:44:01 rhaal kernel: smp_invltlb() at smp_invltlb+0x229 0xffffffff80a2d3c1 
| Jul 15 12:44:01 rhaal kernel: pmap_qenter() at pmap_qenter+0x6d 0xffffffff80a260f0 
| Jul 15 12:44:01 rhaal kernel: allocbuf() at allocbuf+0x5eb 0xffffffff80669b92 
| Jul 15 12:44:01 rhaal kernel: getblk() at getblk+0x467 0xffffffff8066ccff 
| Jul 15 12:44:01 rhaal kernel: hammer_io_inval() at hammer_io_inval+0x84 0xffffffff80821c6e 
| Jul 15 12:44:01 rhaal kernel: hammer_del_buffers() at hammer_del_buffers+0x1cb 0xffffffff8082e06c 
| Jul 15 12:44:01 rhaal kernel: hammer_io_direct_wait() at hammer_io_direct_wait+0xd2 0xffffffff808231f4 
| Jul 15 12:44:01 rhaal kernel: hammer_ip_sync_record_cursor() at hammer_ip_sync_record_cursor+0xcb 0xffffffff80829556 
| Jul 15 12:44:01 rhaal kernel: hammer_sync_record_callback() at hammer_sync_record_callback+0x24d 0xffffffff8081b45c 
| Jul 15 12:44:01 rhaal kernel: hammer_rec_rb_tree_RB_SCAN() at hammer_rec_rb_tree_RB_SCAN+0xfa 0xffffffff80826844 
| Jul 15 12:44:01 rhaal kernel: hammer_sync_inode() at hammer_sync_inode+0x27e 0xffffffff8081db74 
| Jul 15 12:44:01 rhaal kernel: hammer_flusher_flush_inode() at hammer_flusher_flush_inode+0x55 0xffffffff80819f84 
| Jul 15 12:44:01 rhaal kernel: hammer_fls_rb_tree_RB_SCAN() at hammer_fls_rb_tree_RB_SCAN+0xfc 0xffffffff808190fd 
| Jul 15 12:44:01 rhaal kernel: hammer_flusher_slave_thread() at hammer_flusher_slave_thread+0x7a 0xffffffff80819231 
| Jul 15 12:44:01 rhaal kernel: smp_invltlb: endless loop 00000000 00000002, rflags 0000000000000286 retrysmp_invltlb: ipi sent

The machine thankfully is still running.

The kernel is master edca023af (or at most one or two commits after
that).  I‘ll try out today‘s master on a second machine tomorrow, but
until booting is still flakey, it’s difficult to replicate the setup to
reliably provoke a crash.  The dmesg is attached for reference.

Thanks,
    Stefan

-- 
Die Internetbleibe.  Schick, magisch, leistungsstark.
https://internetbleibe.de/

medoly media UG (haftungsbeschränkt), Hausburgstr. 13, 10249 Berlin

E-Mail: info at medolymedia.de
Telefon 030 - 609 826 560
Fax 030 - 609 826 569
Website: https://medolymedia.de/

Geschäftsführer: Matthias Nothhaft, HRB 131198 (Amtsgericht Berlin-Charlottenburg), Sitz: Berlin, USt-ID: DE275221203
-------------- next part --------------
Copyright (c) 2003-2016 The DragonFly Project.
Copyright (c) 1992-2003 The FreeBSD Project.
Copyright (c) 1979, 1980, 1983, 1986, 1988, 1989, 1991, 1992, 1993, 1994
	The Regents of the University of California. All rights reserved.
DragonFly 4.5-DEVELOPMENT #1: Wed Jul  6 09:59:00 UTC 2016
    root at nur-ab-sal:/usr/obj/usr/src/sys/X86_64_GENERIC
i8254 clock: 1193182 Hz
TSC clock: 2600096795 Hz
CPU: AMD Opteron 62xx class CPU (2600.10-MHz K8-class CPU)
  Origin = "AuthenticAMD"  Id = 0x600f12  Stepping = 2
  Features=0x783fbff<FPU,VME,DE,PSE,TSC,MSR,PAE,MCE,CX8,APIC,SEP,MTRR,PGE,MCA,CMOV,PAT,PSE36,MMX,FXSR,SSE,SSE2>
  Features2=0x96982203<SSE3,PCLMULQDQ,SSSE3,CX16,SSE4.1,SSE4.2,POPCNT,AESNI,XSAVE,AVX,VMM>
  AMD Features=0x24500800<SYSCALL,NX,MMX+,Page1GB,LM>
  AMD Features2=0x10be7<LAHF,CMP,SVM,ABM,SSE4A,MAS,Prefetch,OSVW,XOP,FMA4>
  MONITOR/MWAIT Features=0x2<INTBRK>
real memory  = 3219762176 (3070 MB)
avail memory = 2990989312 (2852 MB)
lapic: divisor index 0, frequency 500003110 Hz
SMI Frequency (worst case): 45454 Hz (22 us)
Initialize MI interrupts
wdog: In-kernel automatic watchdog reset enabled
kbd1 at kbdmux0
md0: Preloaded image <initrd.img> 15728640 bytes at 0xffffffff826fc470
md1: Malloc disk
ACPI: RSDP 0x00000000000FC970 000014 (v00 BOCHS )
ACPI: RSDT 0x00000000BFFFBCA0 000040 (v01 BOCHS  BXPCRSDT 00000001 BXPC 00000001)
ACPI: FACP 0x00000000BFFFFF80 000074 (v01 BOCHS  BXPCFACP 00000001 BXPC 00000001)
ACPI: DSDT 0x00000000BFFFBCE0 00151D (v01 BXPC   BXDSDT   00000001 INTL 20100528)
ACPI: FACS 0x00000000BFFFFF40 000040
ACPI: APIC 0x00000000BFFFFC60 000270 (v01 BOCHS  BXPCAPIC 00000001 BXPC 00000001)
ACPI: HPET 0x00000000BFFFFC20 000038 (v01 BOCHS  BXPCHPET 00000001 BXPC 00000001)
ACPI: SRAT 0x00000000BFFFF770 0004A8 (v01 BOCHS  BXPCSRAT 00000001 BXPC 00000001)
ACPI: SSDT 0x00000000BFFFD8E0 001E8E (v01 BOCHS  BXPCSSDT 00000001 BXPC 00000001)
ACPI: SSDT 0x00000000BFFFD870 00003D (v01 BOCHS  BXPCSSDT 00000001 BXPC 00000001)
ACPI: SSDT 0x00000000BFFFD200 00066E (v01 BXPC   BXSSDTPC 00000001 INTL 20100528)
cryptosoft0: <software crypto> on motherboard
aesni0: <AES-CBC,AES-XTS> on motherboard
padlock0: No ACE support.
rdrand0: No RdRand support.
acpi0: <BOCHS BXPCRSDT> on motherboard
ACPI: 4 ACPI AML tables successfully acquired and loaded
ACPI FADT: SCI testing interrupt mode ...
ACPI FADT: SCI select level/low
objcache_reclaimlist
objcache_reclaimlist
objcache_reclaimlist
objcache_reclaimlist
acpi0: Power Button (fixed)
acpi_timer0 on acpi0
acpi_hpet0: <High Precision Event Timer> iomem 0xfed00000-0xfed003ff on acpi0
acpi_hpet0: frequency 100000000
pcib0: <ACPI Host-PCI bridge> port 0xcf8-0xcff on acpi0
pci0: <ACPI PCI bus> on pcib0
pci_link4: Unable to route IRQs: AE_NOT_FOUND
isab0: <PCI-ISA bridge> at device 1.0 on pci0
isa0: <ISA bus> on isab0
atapci0: <Intel PIIX3 WDMA2 controller> port 0xc160-0xc16f,0x376,0x170-0x177,0x3f6,0x1f0-0x1f7 at device 1.1 on pci0
ata0: <ATA channel 0> on atapci0
ata1: <ATA channel 1> on atapci0
acd0: DVDROM <QEMU DVD-ROM/1.0> at ata1-master WDMA2
uhci0: <Intel 82371SB (PIIX3) USB controller> port 0xc100-0xc11f irq 11 at device 1.2 on pci0
usbus0: controller did not stop
usbus0 on uhci0
pci0: <bridge> (vendor 0x8086, dev 0x7113) at device 1.3 irq 9
vgapci0: <VGA-compatible display> mem 0xfd000000-0xfdffffff at device 2.0 on pci0
vgapci0: Boot video device
virtio_pci0: <VirtIO PCI Balloon adapter> port 0xc120-0xc13f irq 11 at device 3.0 on pci0
virtio_pci1: <VirtIO PCI Block adapter> port 0xc000-0xc03f mem 0xfebf0000-0xfebf0fff irq 10 at device 5.0 on pci0
vtblk0: <VirtIO Block Adapter> on virtio_pci1
virtio_pci1: host features: 0x710006d4 <EventIdx,RingIndirect,NotifyOnEmpty,Topology,WriteCache,SCSICmds,BlockSize,DiskGeometry,MaxNumSegs>
virtio_pci1: negotiated features: 0x10000254 <RingIndirect,WriteCache,BlockSize,DiskGeometry,MaxNumSegs>
virtio_pci2: <VirtIO PCI Block adapter> port 0xc040-0xc07f mem 0xfebf1000-0xfebf1fff irq 10 at device 6.0 on pci0
vtblk1: <VirtIO Block Adapter> on virtio_pci2
virtio_pci2: host features: 0x710006d4 <EventIdx,RingIndirect,NotifyOnEmpty,Topology,WriteCache,SCSICmds,BlockSize,DiskGeometry,MaxNumSegs>
virtio_pci2: negotiated features: 0x10000254 <RingIndirect,WriteCache,BlockSize,DiskGeometry,MaxNumSegs>
virtio_pci3: <VirtIO PCI Network adapter> port 0xc140-0xc15f mem 0xfebf2000-0xfebf2fff irq 11 at device 7.0 on pci0
vtnet0: <VirtIO Networking Adapter> on virtio_pci3
virtio_pci3: host features: 0x711f8060 <EventIdx,RingIndirect,NotifyOnEmpty,RxModeExtra,VLanFilter,RxMode,ControlVq,Status,MrgRxBuf,TxAllGSO,MacAddress>
virtio_pci3: negotiated features: 0x110f8020 <RingIndirect,NotifyOnEmpty,VLanFilter,RxMode,ControlVq,Status,MrgRxBuf,MacAddress>
usbus0: 12Mbps Full Speed USB v1.0
vtnet0: MAC address: 02:01:06:f6:1b:63
add dynamic link state
virtio_pci4: <VirtIO PCI Block adapter> port 0xc080-0xc0bf mem 0xfebf3000-0xfebf3fff irq 11 at device 8.0 on pci0
vtblk2: <VirtIO Block Adapter> on virtio_pci4
virtio_pci4: host features: 0x710006d4 <EventIdx,RingIndirect,NotifyOnEmpty,Topology,WriteCache,SCSICmds,BlockSize,DiskGeometry,MaxNumSegs>
virtio_pci4: negotiated features: 0x10000254 <RingIndirect,WriteCache,BlockSize,DiskGeometry,MaxNumSegs>
virtio_pci5: <VirtIO PCI Block adapter> port 0xc0c0-0xc0ff mem 0xfebf4000-0xfebf4fff irq 10 at device 9.0 on pci0
vtblk3: <VirtIO Block Adapter> on virtio_pci5
virtio_pci5: host features: 0x710006d4 <EventIdx,RingIndirect,NotifyOnEmpty,Topology,WriteCache,SCSICmds,BlockSize,DiskGeometry,MaxNumSegs>
virtio_pci5: negotiated features: 0x10000254 <RingIndirect,WriteCache,BlockSize,DiskGeometry,MaxNumSegs>
atkbdc0: <Keyboard controller (i8042)> port 0x64,0x60 irq 1 on acpi0
atkbd0: <AT Keyboard> irq 1 on atkbdc0
kbd0 at atkbd0
ugen0.1: <Intel> at usbus0
uhub0: <Intel UHCI root HUB, class 9/0, rev 1.00/1.00, addr 1> on usbus0
psm0: <PS/2 Mouse> irq 12 on atkbdc0
psm0: model IntelliMouse Explorer, device ID 4
cpu0: <ACPI CPU> on acpi0
cpu_cst0: <ACPI CPU C-State> on cpu0
cpu1: <ACPI CPU> on acpi0
cpu_cst1: <ACPI CPU C-State> on cpu1
ACPI: Enabled 16 GPEs in block 00 to 0F
orm0: <ISA Option ROM> at iomem 0xe7800-0xeffff on isa0
pmtimer0 on isa0
vga0: <Generic ISA VGA> at port 0x3c0-0x3df iomem 0xa0000-0xbffff on isa0
sc0: <System console> at flags 0x500 on isa0
sc0: VGA <16 virtual consoles, flags=0x300>
sio0 at port 0x3f8-0x3ff irq 4 flags 0x10 on isa0
sio0: type 16550A
sio1: can't drain, serial port might not exist, disabling
hpt27xx: no controller detected.
CAM: Configuring 2 busses
uhub0: 2 ports with 2 removable, self powered
CAM: finished configuring all busses
cd0 at ata1 bus 0 target 0 lun 0
cd0: <QEMU QEMU DVD-ROM 1.0> Removable CD-ROM SCSI-0 device 
cd0: 16.000MB/s transfers
cd0: cd present [329728 x 2048 byte records]
ugen0.2: <QEMU> at usbus0
uhid0: <QEMU QEMU USB Tablet, class 0/0, rev 1.00/0.00, addr 2> on usbus0
no B_DEVMAGIC (bootdev=0)
Device Mapper version 4.16.0 loaded
dm_target_zero: Successfully initialized
dm_target_crypt: Successfully initialized
dm_target_error: Successfully initialized
Mounting root from ufs:md0s0
DMA space used: 5340k, remaining available: 131072k
Mounting devfs
dm_target_crypt: Setting min/max mpipe buffers: 2/30
dm_target_crypt: Setting min/max mpipe buffers: 2/30
HAMMER(Rhaal) recovery check seqno=077a67f9
HAMMER(Rhaal) recovery range 300000001078d1c8-3000000010793d10
HAMMER(Rhaal) recovery nexto 300000001078d1c8 endseqno=077a68e7
HAMMER(Rhaal) recovery undo  300000001078d1c8-3000000010793d10 (27464 bytes) (RO)
HAMMER(Rhaal) Found REDO_SYNC 300000001078d200
HAMMER(Rhaal) recovery complete
chroot_kernel: set new rootnch/rootvnode to /new_root
dm_target_crypt: Setting min/max mpipe buffers: 2/30
dm_target_crypt: Setting min/max mpipe buffers: 2/30
dm_target_crypt: Setting min/max mpipe buffers: 2/30
dm_target_crypt: Setting min/max mpipe buffers: 2/30
dm_target_crypt: Setting min/max mpipe buffers: 2/30
HAMMER: read-only -> read-write
HAMMER(Rhaal) recovery redo  300000001078d1c8-3000000010793d10 (27464 bytes)(RW)
HAMMER(Rhaal) Embedded extended redo 300000001078d200, -56 extbytes
HAMMER(Rhaal) End redo recovery
HAMMER(Rhaal-Daten) recovery check seqno=50175620
HAMMER(Rhaal-Daten) recovery range 30000000162234d0-300000001622a540
HAMMER(Rhaal-Daten) recovery nexto 30000000162234d0 endseqno=5017565c
HAMMER(Rhaal-Daten) recovery undo  30000000162234d0-300000001622a540 (28784 bytes)(RW)
HAMMER(Rhaal-Daten) Found REDO_SYNC 30000000162234d0
HAMMER(Rhaal-Daten) recovery complete
HAMMER(Rhaal-Daten) recovery redo  30000000162234d0-300000001622a540 (28784 bytes)(RW)
HAMMER(Rhaal-Daten) Embedded extended redo 30000000162234d0, 0 extbytes
HAMMER(Rhaal-Daten) End redo recovery
HAMMER(Rhaal-Backup) recovery check seqno=019dbb43
HAMMER(Rhaal-Backup) recovery range 30000000056e1578-30000000056e1578
HAMMER(Rhaal-Backup) recovery nexto 30000000056e1578 endseqno=019dbb44
HAMMER(Rhaal-Backup) mounted clean, no recovery needed
dm_target_crypt: Setting min/max mpipe buffers: 2/30
swap low/high-water marks set to 83874/125811