kern/127439: [pf] deadlock in pf

Philippe Pepiot phil at philpep.org
Sat Sep 11 14:30:09 UTC 2010


The following reply was made to PR kern/127439; it has been noted by GNATS.

From: Philippe Pepiot <phil at philpep.org>
To: bug-followup at FreeBSD.org
Cc: mainland at apeiron.net, csjp at freebsd.org
Subject: Re: kern/127439: [pf] deadlock in pf
Date: Sat, 11 Sep 2010 16:04:31 +0200

 Hi, this lock still exists on 8.1-RELEASE.
 
 $ cat /etc/pf.conf
 set block-policy return
 block all
 pass out proto { tcp udp } to port domain
 pass out proto tcp to port { http ftp } user root 
 
 My box deadlock at boot i suppose a minimal DNS traffic start cause pf
 to evaluate rules.
 
 without one of theses rules no deadlock.
 
 $ uname -a
 FreeBSD aldo.philpep.org 8.1-RELEASE FreeBSD 8.1-RELEASE #3: Sat Sep 11
 11:05:55 UTC 2010     root at aldo.philpep.org:/usr/obj/usr/src/sys/ALDO
 amd64
 
 (as you can see i've ipv6 and ipv4 enabled)
 
 
 /boot/kernel/kernel text=0x64d7a6 data=0x916e8+0x23f1c8 syms=[0x8+0xabd68+0x8+0x9c3b7]
 /boot/kernel/zfs.ko size 0x1a3098 at 0xc67000
 loading required module 'opensolaris'
 /boot/kernel/opensolaris.ko size 0x3948 at 0xe0b000
 /
 Hit [Enter] to boot immediately, or any other key for command prompt.
 Booting [/boot/kernel/kernel]...               
 KDB: debugger backends: ddb
 KDB: current backend: ddb
 Copyright (c) 1992-2010 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.
 FreeBSD is a registered trademark of The FreeBSD Foundation.
 FreeBSD 8.1-RELEASE #3: Sat Sep 11 11:05:55 UTC 2010
     root at aldo.philpep.org:/usr/obj/usr/src/sys/ALDO amd64
 WARNING: WITNESS option enabled, expect reduced performance.
 WARNING: DIAGNOSTIC option enabled, expect reduced performance.
 Timecounter "i8254" frequency 1193182 Hz quality 0
 CPU: Intel(R) Celeron(R) CPU        E3300  @ 2.50GHz (2493.11-MHz K8-class CPU)
   Origin = "GenuineIntel"  Id = 0x1067a  Family = 6  Model = 17  Stepping = 10
   Features=0xbfebfbff<FPU,VME,DE,PSE,TSC,MSR,PAE,MCE,CX8,APIC,SEP,MTRR,PGE,MCA,CMOV,PAT,PSE36,CLFLUSH,DTS,ACPI,MMX,FXSR,SSE,SSE2,SS,HTT,TM,PBE>
   Features2=0x400e3bd<SSE3,DTES64,MON,DS_CPL,VMX,EST,TM2,SSSE3,CX16,xTPR,PDCM,XSAVE>
   AMD Features=0x20000800<SYSCALL,LM>
   AMD Features2=0x1<LAHF>
   TSC: P-state invariant
 real memory  = 4294967296 (4096 MB)
 avail memory = 3841851392 (3663 MB)
 ACPI APIC Table: <110309 APIC2133>
 FreeBSD/SMP: Multiprocessor System Detected: 2 CPUs
 FreeBSD/SMP: 1 package(s) x 2 core(s)
  cpu0 (BSP): APIC ID:  0
  cpu1 (AP): APIC ID:  1
 ioapic0 <Version 2.0> irqs 0-23 on motherboard
 kbd1 at kbdmux0
 cryptosoft0: <software crypto> on motherboard
 acpi0: <110309 RSDT2133> on motherboard
 acpi0: [ITHREAD]
 acpi0: Power Button (fixed)
 acpi0: reservation of 0, a0000 (3) failed
 acpi0: reservation of 100000, cfd00000 (3) failed
 Timecounter "ACPI-fast" frequency 3579545 Hz quality 1000
 acpi_timer0: <24-bit timer at 3.579545MHz> port 0x808-0x80b on acpi0
 cpu0: <ACPI CPU> on acpi0
 cpu1: <ACPI CPU> on acpi0
 pcib0: <ACPI Host-PCI bridge> port 0xcf8-0xcff on acpi0
 pci0: <ACPI PCI bus> on pcib0
 vgapci0: <VGA-compatible display> port 0xdc00-0xdc07 mem 0xfe400000-0xfe7fffff,0xe0000000-0xefffffff irq 16 at device 2.0 on pci0
 agp0: <Intel G41 SVGA controller> on vgapci0
 agp0: detected 262140k stolen memory
 agp0: aperture size is 256M
 pci0: <multimedia, HDA> at device 27.0 (no driver attached)
 pcib1: <ACPI PCI-PCI bridge> irq 16 at device 28.0 on pci0
 pci2: <ACPI PCI bus> on pcib1
 pcib2: <ACPI PCI-PCI bridge> irq 17 at device 28.1 on pci0
 pci1: <ACPI PCI bus> on pcib2
 alc0: <Atheros AR8132 PCIe Fast Ethernet> port 0xec00-0xec7f mem 0xfebc0000-0xfebfffff irq 17 at device 0.0 on pci1
 alc0: 15872 Tx FIFO, 15360 Rx FIFO
 alc0: Using 1 MSI message(s).
 alc0: 4GB boundary crossed, switching to 32bit DMA addressing mode.
 miibus0: <MII bus> on alc0
 atphy0: <Atheros F1 10/100/1000 PHY> PHY 0 on miibus0
 atphy0:  10baseT, 10baseT-FDX, 100baseTX, 100baseTX-FDX, auto
 alc0: Ethernet address: 00:25:22:15:70:2b
 alc0: [FILTER]
 uhci0: <Intel 82801G (ICH7) USB controller USB-A> port 0xd400-0xd41f irq 23 at device 29.0 on pci0
 uhci0: [ITHREAD]
 uhci0: LegSup = 0x2f00
 usbus0: <Intel 82801G (ICH7) USB controller USB-A> on uhci0
 uhci1: <Intel 82801G (ICH7) USB controller USB-B> port 0xd480-0xd49f irq 19 at device 29.1 on pci0
 uhci1: [ITHREAD]
 uhci1: LegSup = 0x2f00
 usbus1: <Intel 82801G (ICH7) USB controller USB-B> on uhci1
 uhci2: <Intel 82801G (ICH7) USB controller USB-C> port 0xd800-0xd81f irq 18 at device 29.2 on pci0
 uhci2: [ITHREAD]
 uhci2: LegSup = 0x2f00
 usbus2: <Intel 82801G (ICH7) USB controller USB-C> on uhci2
 uhci3: <Intel 82801G (ICH7) USB controller USB-D> port 0xd880-0xd89f irq 16 at device 29.3 on pci0
 uhci3: [ITHREAD]
 uhci3: LegSup = 0x2f00
 usbus3: <Intel 82801G (ICH7) USB controller USB-D> on uhci3
 ehci0: <Intel 82801GB/R (ICH7) USB 2.0 controller> mem 0xfeaf7c00-0xfeaf7fff irq 23 at device 29.7 on pci0
 ehci0: [ITHREAD]
 usbus4: EHCI version 1.0
 usbus4: <Intel 82801GB/R (ICH7) USB 2.0 controller> on ehci0
 pcib3: <ACPI PCI-PCI bridge> at device 30.0 on pci0
 pci3: <ACPI PCI bus> on pcib3
 isab0: <PCI-ISA bridge> at device 31.0 on pci0
 isa0: <ISA bus> on isab0
 atapci0: <Intel ICH7 UDMA100 controller> port 0x1f0-0x1f7,0x3f6,0x170-0x177,0x376,0xffa0-0xffaf at device 31.1 on pci0
 ata0: <ATA channel 0> on atapci0
 ata0: [ITHREAD]
 atapci1: <Intel ICH7 SATA300 controller> port 0xd080-0xd087,0xd000-0xd003,0xcc00-0xcc07,0xc880-0xc883,0xc800-0xc80f irq 19 at device 31.2 on pci0
 atapci1: [ITHREAD]
 ata2: <ATA channel 0> on atapci1
 ata2: [ITHREAD]
 ata3: <ATA channel 1> on atapci1
 ata3: [ITHREAD]
 pci0: <serial bus, SMBus> at device 31.3 (no driver attached)
 acpi_button0: <Power Button> on acpi0
 atrtc0: <AT realtime clock> port 0x70-0x71 irq 8 on acpi0
 uart0: <16550 or compatible> port 0x3f8-0x3ff irq 4 flags 0x10 on acpi0
 uart0: [FILTER]
 uart0: console (9600,n,8,1)
 sc0: <System console> at flags 0x100 on isa0
 sc0: VGA <16 virtual consoles, flags=0x100>
 vga0: <Generic ISA VGA> at port 0x3c0-0x3df iomem 0xa0000-0xbffff on isa0
 atkbdc0: <Keyboard controller (i8042)> at port 0x60,0x64 on isa0
 atkbd0: <AT Keyboard> irq 1 on atkbdc0
 kbd0 at atkbd0
 atkbd0: [GIANT-LOCKED]
 atkbd0: [ITHREAD]
 coretemp0: <CPU On-Die Thermal Sensors> on cpu0
 est0: <Enhanced SpeedStep Frequency Control> on cpu0
 est: CPU supports Enhanced Speedstep, but is not recognized.
 est: cpu_vendor GenuineIntel, msr 6164c2406004a24
 device_attach: est0 attach returned 6
 p4tcc0: <CPU Frequency Thermal Control> on cpu0
 coretemp1: <CPU On-Die Thermal Sensors> on cpu1
 est1: <Enhanced SpeedStep Frequency Control> on cpu1
 est: CPU supports Enhanced Speedstep, but is not recognized.
 est: cpu_vendor GenuineIntel, msr 6164c2406004a24
 device_attach: est1 attach returned 6
 p4tcc1: <CPU Frequency Thermal Control> on cpu1
 ZFS filesystem version 3
 ZFS storage pool version 14
 Timecounters tick every 1.000 msec
 usbus0: 12Mbps Full Speed USB v1.0
 usbus1: 12Mbps Full Speed USB v1.0
 usbus2: 12Mbps Full Speed USB v1.0
 usbus3: 12Mbps Full Speed USB v1.0
 usbus4: 480Mbps High Speed USB v2.0
 ad4: 476940MB <WDC WD5000AAKS-00WWPA0 01.03B01> at ata2-master UDMA100 SATA
 ugen0.1: <Intel> at usbus0
 uhub0: <Intel UHCI root HUB, class 9/0, rev 1.00/1.00, addr 1> on usbus0
 Expensive timeout(9) function: 0xffffffff8042a350(0xffffff0001900ba0) 0.119308459 s
 ugen1.1: <Intel> at usbus1
 uhub1: <Intel UHCI root HUB, class 9/0, rev 1.00/1.00, addr 1> on usbus1
 ugen2.1: <Intel> at usbus2
 uhub2: <Intel UHCI root HUB, class 9/0, rev 1.00/1.00, addr 1> on usbus2
 ugen3.1: <Intel> at usbus3
 uhub3: <Intel UHCI root HUB, class 9/0, rev 1.00/1.00, addr 1> on usbus3
 ugen4.1: <Intel> at usbus4
 uhub4: <Intel EHCI root HUB, class 9/0, rev 2.00/1.00, addr 1> on usbus4
 SMP: AP CPU #1 Launched!
 WARNING: WITNESS option enabled, expect reduced performance.
 WARNING: DIAGNOSTIC option enabled, expect reduced performance.
 Root mount waiting for: usbus4 usbus3 usbus2 usbus1 usbus0
 uhub0: 2 ports with 2 removable, self powered
 uhub1: 2 ports with 2 removable, self powered
 uhub2: 2 ports with 2 removable, self powered
 uhub3: 2 ports with 2 removable, self powered
 Root mount waiting for: usbus4
 Root mount waiting for: usbus4
 uhub4: 8 ports with 8 removable, self powered
 Trying to mount root from zfs:tank/root
 Setting hostuuid: 00020003-0004-0005-0006-000700080009.
 Setting hostid: 0x81f4ec68.
 Entropy harvesting: interrupts ethernet point_to_point kickstart.
 Starting file system checks:
 Mounting local file systems:.
 Setting hostname: aldo.philpep.org.
 alc0: link state changed to DOWN
 Starting Network: lo0 alc0.
 lo0: flags=8049<UP,LOOPBACK,RUNNING,MULTICAST> metric 0 mtu 16384
 	options=3<RXCSUM,TXCSUM>
 	inet 127.0.0.1 netmask 0xff000000 
 	inet6 ::1 prefixlen 128 
 	inet6 fe80::1%lo0 prefixlen 64 scopeid 0x2 
 	nd6 options=3<PERFORMNUD,ACCEPT_RTADV>
 alc0: flags=8843<UP,BROADCAST,RUNNING,SIMPLEX,MULTICAST> metric 0 mtu 1500
 	options=c3198<VLAN_MTU,VLAN_HWTAGGING,VLAN_HWCSUM,TSO4,WOL_MCAST,WOL_MAGIC,VLAN_HWTSO,LINKSTATE>
 	ether 00:25:22:15:70:2b
 	inet 192.168.0.20 netmask 0xffffff00 broadcast 192.168.0.255
 	inet6 fe80::225:22ff:fe15:702b%alc0 prefixlen 64 tentative scopeid 0x1 
 	nd6 options=3<PERFORMNUD,ACCEPT_RTADV>
 	media: Ethernet autoselect (none)
 	status: no carrier
 Enabling pfpf enabled
 .
 add net default: gateway 192.168.0.1
 add net ::ffff:0.0.0.0: gateway ::1
 add net ::0.0.0.0: gateway ::1
 net.inet6.ip6.forwarding: 0 -> 0
 alc0: flags=8843<UP,BROADCAST,RUNNING,SIMPLEX,MULTICAST> metric 0 mtu 1500
 	options=c3198<VLAN_MTU,VLAN_HWTAGGING,VLAN_HWCSUM,TSO4,WOL_MCAST,WOL_MAGIC,VLAN_HWTSO,LINKSTATE>
 	inet6 fe80::225:22ff:fe15:702b%alc0 prefixlen 64 tentative scopeid 0x1 
 	inet6 2001:470:1f15:7bf:dead:c0de:0:20 prefixlen 96 tentative 
 lo0: flags=8049<UP,LOOPBACK,RUNNING,MULTICAST> metric 0 mtu 16384
 	options=3<RXCSUM,TXCSUM>
 	inet6 ::1 prefixlen 128 
 	inet6 fe80::1%lo0 prefixlen 64 scopeid 0x2 
 pflog0: flags=0<> metric 0 mtu 33152
 alc0: link state changed to UP
 add net fe80::: gateway ::1
 add net ff02::: gateway ::1
 add net default: gateway 2001:470:1f15:7bf:dead:c0de::1
 IPv4 mapped IPv6 address support=NO
 Starting devd.
 ELF ldconfig path: /lib /usr/lib /usr/lib/compat /usr/local/lib /usr/local/lib/zsh
 32-bit compatibility ldconfig path:
 Creating and/or trimming log files.
 Starting syslogd.
 Clearing /tmp (X related).
 Recovering vi editor sessions:lock order reversal:
  1st 0xffffffff80ac42a8 PFil hook read/write mutex (PFil hook read/write mutex) @ /usr/src/sys/net/pfil.c:77
  2nd 0xffffffff80ac5aa8 udp (udp) @ /usr/src/sys/contrib/pf/net/pf.c:3035
 KDB: stack backtrace:
 db_trace_self_wrapper() at db_trace_self_wrapper+0x2a
 _witness_debugger() at _witness_debugger+0x2e
 witness_checkorder() at witness_checkorder+0x81e
 _rw_rlock() at _rw_rlock+0x5f
 pf_socket_lookup() at pf_socket_lookup+0x1c7
 pf_test_udp() at pf_test_udp+0x8ce
 pf_test() at pf_test+0x1125
 pf_check_in() at pf_check_in+0x39
 pfil_run_hooks() at pfil_run_hooks+0xcf
 ip_input() at ip_input+0x2cd
 swi_net() at swi_net+0x151
 intr_event_execute_handlers() at intr_event_execute_handlers+0x66
 ithread_loop() at ithread_loop+0xb2
 fork_exit() at fork_exit+0x12a
 fork_trampoline() at fork_trampoline+0xe
 --- trap 0, rip = 0, rsp = 0xffffff8000041d30, rbp = 0 ---
 panic: _rw_rlock (tcp): wlock already held @ /usr/src/sys/contrib/pf/net/pf.c:3059
 cpuid = 1
 KDB: enter: panic
 [thread pid 856 tid 100103 ]
 Stopped at      kdb_enter+0x3d: movq    $0,0x4fdd00(%rip)
 db> 
 
 
 db> ps
   pid  ppid  pgrp   uid   state   wmesg         wchan        cmd
   856   851    25    25  R+      CPU 1                       sendmail
   851    25    25     0  S+      wait     0xffffff00035ff460 sh
   720     1   720     0  Ss      select   0xffffff0003985b40 syslogd
   582     1   582     0  Ss      select   0xffffff00036d4940 devd
    25     1    25     0  Ss+     wait     0xffffff00034938c0 sh
    24     0     0     0  SL      flowclea 0xffffffff80abf5d0 [flowcleaner]
    23     0     0     0  SL      sdflush  0xffffffff80ad0ef8 [softdepflush]
    22     0     0     0  SL      vlruwt   0xffffff0003065000 [vnlru]
    21     0     0     0  SL      syncer   0xffffffff80abf320 [syncer]
    20     0     0     0  SL      psleep   0xffffffff80abee48 [bufdaemon]
    19     0     0     0  SL      pgzero   0xffffffff80ad298c [pagezero]
    18     0     0     0  SL      psleep   0xffffffff80ad1d28 [vmdaemon]
    17     0     0     0  SL      psleep   0xffffffff80ad1cec [pagedaemon]
    16     0     0     0  SL      ccb_scan 0xffffffff808e0760 [xpt_thrd]
    15     0     0     0  SL      jsw:wait 0xffffffff808fa450 [g_journal switcher]
     9     0     0     0  SL      pftm     0xffffffff801d8d80 [pfpurge]
     8     0     0     0  SL      waiting_ 0xffffffff80ac48e0 [sctp_iterator]
     7     0     0     0  SL      (threaded)                  zfskern
 100098                   D       tx->tx_s 0xffffff0003196a40 [txg_thread_enter]
 100097                   D       tx->tx_q 0xffffff0003196a60 [txg_thread_enter]
 100057                   D       l2arc_fe 0xffffffff80d5ffc0 [l2arc_feed_thread]
 100056                   D       arc_recl 0xffffffff80d50120 [arc_reclaim_thread]
    14     0     0     0  SL      (threaded)                  usb
 [... usb bus ...]
     6     0     0     0  SL      crypto_r 0xffffffff80acfd40 [crypto returns]
     5     0     0     0  SL      crypto_w 0xffffffff80acfd00 [crypto]
    13     0     0     0  SL      -        0xffffffff808fdd44 [yarrow]
     4     0     0     0  SL      -        0xffffffff808fa3c8 [g_down]
     3     0     0     0  SL      -        0xffffffff808fa3c0 [g_up]
     2     0     0     0  SL      -        0xffffffff808fa3b0 [g_event]
    12     0     0     0  WL      (threaded)                  intr
 100053                   I                                   [irq1: atkbd0]
 100052                   I                                   [swi0: uart]
 100051                   I                                   [irq14: ata0]
 100042                   I                                   [irq16: uhci3]
 100037                   I                                   [irq18: uhci2]
 100032                   I                                   [irq19: uhci1+]
 100027                   I                                   [irq23: uhci0 ehci0]
 100025                   I                                   [irq9: acpi0]
 100023                   I                                   [swi2: cambio]
 100019                   I                                   [swi6: task queue]
 100018                   I                                   [swi6: Giant taskq]
 100016                   I                                   [swi5: +]
 100008                   I                                   [swi4: clock]
 100007                   I                                   [swi4: clock]
 100006                   I                                   [swi3: vm]
 100005                   I                                   [swi1: netisr 0]
    11     0     0     0  RL      (threaded)                  idle
 100004                   Run     CPU 0                       [idle: cpu0]
 100003                   CanRun                              [idle: cpu1]
     1     0     1     0  SLs     wait     0xffffff000149d8c0 [init]
    10     0     0     0  SL      audit_wo 0xffffffff80ad0250 [audit]
     0     0     0     0  SLs     (threaded)                  kernel
 100141                   D       -        0xffffff00036d5a00 [zil_clean]
 [... zil_clean ...]
 100096                   D       -        0xffffff00030b8000 [zfs_vn_rele_taskq]
 100095                   D       -        0xffffff00030b8700 [spa_zio]
 [... spa_zio ... ]
 100055                   D       -        0xffffff0001fb4c00 [system_taskq_1]
 100054                   D       -        0xffffff0001fb4c00 [system_taskq_0]
 100026                   D       -        0xffffff0001700600 [alc0 taskq]
 100024                   D       -        0xffffff0001589c80 [kqueue taskq]
 100022                   D       -        0xffffff000158a100 [acpi_task_2]
 100021                   D       -        0xffffff000158a100 [acpi_task_1]
 100020                   D       -        0xffffff000158a100 [acpi_task_0]
 100017                   D       -        0xffffff000152ea00 [thread taskq]
 100012                   D       -        0xffffff000149ad80 [firmware taskq]
 100000                   D       sched    0xffffffff808fa5c0 [swapper]
 
 
 if you're interested by a proccess trace just ask.


More information about the freebsd-pf mailing list