On Mon, Sep 26, 2016 at 11:33:12AM +0200, Julien Charbon wrote:
>
> Hi Slawa,
>
> On 9/25/16 2:46 PM, Slawa Olhovchenkov wrote:
> > On Fri, Sep 23, 2016 at 11:01:43PM +0300, Slawa Olhovchenkov wrote:
> >>> On 9/21/16 9:51 PM, Slawa Olhovchenkov wrote:
> >>>> On Wed, Sep 21, 2016 at 09:11:24AM +0200, Julien Charbon
wrote:
> >>>>> You can also use Dtrace and lockstat (especially with
the lockstat -s
> >>>>> option):
> >>>>>
> >>>>>
https://wiki.freebsd.org/DTrace/One-Liners#Kernel_Locks
> >>>>>
https://www.freebsd.org/cgi/man.cgi?query=lockstat&manpath=FreeBSD+11.0-RELEASE
> >>>>>
> >>>>> But I am less familiar with Dtrace/lockstat tools.
> >>>>
> >>>> I am still use old kernel and got lockdown again.
> >>>> Try using lockstat (I am save more output), interesting
may be next:
> >>>>
> >>>> R/W writer spin on writer: 190019 events in 1.070 seconds
(177571 events/sec)
> >>>>
> >>>>
-------------------------------------------------------------------------------
> >>>> Count indv cuml rcnt nsec Lock
Caller
> >>>> 140839 74% 74% 0.00 24659 tcpinp
tcp_tw_2msl_scan+0xc6
> >>>>
> >>>> nsec ------ Time Distribution ------ count Stack
> >>>> 4096 | 913
tcp_twstart+0xa3
> >>>> 8192 |@@@@@@@@@@@@ 58191
tcp_do_segment+0x201f
> >>>> 16384 |@@@@@@ 29594
tcp_input+0xe1c
> >>>> 32768 |@@@@ 23447
ip_input+0x15f
> >>>> 65536 |@@@ 16197
> >>>> 131072 |@ 8674
> >>>> 262144 | 3358
> >>>> 524288 | 456
> >>>> 1048576 | 9
> >>>>
-------------------------------------------------------------------------------
> >>>> Count indv cuml rcnt nsec Lock
Caller
> >>>> 49180 26% 100% 0.00 15929 tcpinp
tcp_tw_2msl_scan+0xc6
> >>>>
> >>>> nsec ------ Time Distribution ------ count Stack
> >>>> 4096 | 157
pfslowtimo+0x54
> >>>> 8192 |@@@@@@@@@@@@@@@ 24796
softclock_call_cc+0x179
> >>>> 16384 |@@@@@@ 11223
softclock+0x44
> >>>> 32768 |@@@@ 7426
intr_event_execute_handlers+0x95
> >>>> 65536 |@@ 3918
> >>>> 131072 | 1363
> >>>> 262144 | 278
> >>>> 524288 | 19
> >>>>
-------------------------------------------------------------------------------
> >>>
> >>> This is interesting, it seems that you have two call paths
competing
> >>> for INP locks here:
> >>>
> >>> - pfslowtimo()/tcp_tw_2msl_scan(reuse=0) and
> >>>
> >>> - tcp_input()/tcp_twstart()/tcp_tw_2msl_scan(reuse=1)
> >>
> >> My current hypothesis:
> >>
> >> nginx do write() (or may be close()?) to socket, kernel lock
> >> first inp in V_twq_2msl, happen callout for pfslowtimo() on the
same
> >> CPU core and tcp_tw_2msl_scan infinity locked on same inp.
> >>
> >> In this case you modification can't help, before next try we
need some
> >> like yeld().
> >
> > Or may be locks leaks.
> > Or both.
>
> You are totally right, pfslowtimo()/tcp_tw_2msl_scan(reuse=0) is
> infinitely blocked on INP_WLOCK() by "something" (that could be
related
> to write()).
>
> As I reached my limit of debugging without WITNESS, could you share
> your /etc/sysctl.conf, /boot/loader.conf files? And any specific
> configuration you have (like having a Nginx workers affinity, Nginx
> special options, etc.). Like that I can try to reproduce it on
releng/11.0.
Some more traces from ddb:
Tracing command intr pid 12 tid 100103 td 0xfffff8012508ea00
sched_switch() at 0xffffffff804c956d = sched_switch+0x6ad/frame
0xfffffe2020ea8330
mi_switch() at 0xffffffff804a8d92 = mi_switch+0xd2/frame 0xfffffe2020ea8360
turnstile_wait() at 0xffffffff804ef177 = turnstile_wait+0x2a7/frame
0xfffffe2020ea83a0
__mtx_lock_sleep() at 0xffffffff80484d9d = __mtx_lock_sleep+0x13d/frame
0xfffffe2020ea8420
sodealloc() at 0xffffffff8051b992 = sodealloc+0x32/frame 0xfffffe2020ea8460
tcp_close() at 0xffffffff80618150 = tcp_close+0xd0/frame 0xfffffe2020ea8490
tcp_do_segment() at 0xffffffff80610226 = tcp_do_segment+0x1666/frame
0xfffffe2020ea8590
tcp_input() at 0xffffffff8060e17c = tcp_input+0xe1c/frame 0xfffffe2020ea86e0
ip_input() at 0xffffffff805a087f = ip_input+0x15f/frame 0xfffffe2020ea8740
netisr_dispatch_src() at 0xffffffff80583db5 = netisr_dispatch_src+0xa5/frame
0xfffffe2020ea87a0
ether_demux() at 0xffffffff80575b3a = ether_demux+0x12a/frame 0xfffffe2020ea87d0
ether_nh_input() at 0xffffffff80576792 = ether_nh_input+0x322/frame
0xfffffe2020ea8830
netisr_dispatch_src() at 0xffffffff80583db5 = netisr_dispatch_src+0xa5/frame
0xfffffe2020ea8890
ether_input() at 0xffffffff80575db6 = ether_input+0x26/frame 0xfffffe2020ea88b0
ixgbe_rxeof() at 0xffffffff813df36b = ixgbe_rxeof+0x7ab/frame 0xfffffe2020ea8990
ixgbe_msix_que() at 0xffffffff813da57c = ixgbe_msix_que+0x8c/frame
0xfffffe2020ea89e0
intr_event_execute_handlers() at 0xffffffff8046c605 =
intr_event_execute_handlers+0x95/frame 0xfffffe2020ea8a20
ithread_loop() at 0xffffffff8046cc26 = ithread_loop+0xa6/frame
0xfffffe2020ea8a70
fork_exit() at 0xffffffff8046a211 = fork_exit+0x71/frame 0xfffffe2020ea8ab0
fork_trampoline() at 0xffffffff806cb50e = fork_trampoline+0xe/frame
0xfffffe2020ea8ab0
--- trap 0, rip = 0, rsp = 0, rbp = 0 ---
Tracing command intr pid 12 tid 100105 td 0xfffff8012508e000
sched_switch() at 0xffffffff804c956d = sched_switch+0x6ad/frame
0xfffffe2020eb2330
mi_switch() at 0xffffffff804a8d92 = mi_switch+0xd2/frame 0xfffffe2020eb2360
turnstile_wait() at 0xffffffff804ef177 = turnstile_wait+0x2a7/frame
0xfffffe2020eb23a0
__mtx_lock_sleep() at 0xffffffff80484d9d = __mtx_lock_sleep+0x13d/frame
0xfffffe2020eb2420
sodealloc() at 0xffffffff8051b992 = sodealloc+0x32/frame 0xfffffe2020eb2460
tcp_close() at 0xffffffff80618150 = tcp_close+0xd0/frame 0xfffffe2020eb2490
tcp_do_segment() at 0xffffffff80610226 = tcp_do_segment+0x1666/frame
0xfffffe2020eb2590
tcp_input() at 0xffffffff8060e17c = tcp_input+0xe1c/frame 0xfffffe2020eb26e0
ip_input() at 0xffffffff805a087f = ip_input+0x15f/frame 0xfffffe2020eb2740
netisr_dispatch_src() at 0xffffffff80583db5 = netisr_dispatch_src+0xa5/frame
0xfffffe2020eb27a0
ether_demux() at 0xffffffff80575b3a = ether_demux+0x12a/frame 0xfffffe2020eb27d0
ether_nh_input() at 0xffffffff80576792 = ether_nh_input+0x322/frame
0xfffffe2020eb2830
netisr_dispatch_src() at 0xffffffff80583db5 = netisr_dispatch_src+0xa5/frame
0xfffffe2020eb2890
ether_input() at 0xffffffff80575db6 = ether_input+0x26/frame 0xfffffe2020eb28b0
ixgbe_rxeof() at 0xffffffff813df36b = ixgbe_rxeof+0x7ab/frame 0xfffffe2020eb2990
ixgbe_msix_que() at 0xffffffff813da57c = ixgbe_msix_que+0x8c/frame
0xfffffe2020eb29e0
intr_event_execute_handlers() at 0xffffffff8046c605 =
intr_event_execute_handlers+0x95/frame 0xfffffe2020eb2a20
ithread_loop() at 0xffffffff8046cc26 = ithread_loop+0xa6/frame
0xfffffe2020eb2a70
fork_exit() at 0xffffffff8046a211 = fork_exit+0x71/frame 0xfffffe2020eb2ab0
fork_trampoline() at 0xffffffff806cb50e = fork_trampoline+0xe/frame
0xfffffe2020eb2ab0
--- trap 0, rip = 0, rsp = 0, rbp = 0 ---
Tracing command intr pid 12 tid 100107 td 0xfffff8012508d500
sched_switch() at 0xffffffff804c956d = sched_switch+0x6ad/frame
0xfffffe2020ebc2b0
mi_switch() at 0xffffffff804a8d92 = mi_switch+0xd2/frame 0xfffffe2020ebc2e0
turnstile_wait() at 0xffffffff804ef177 = turnstile_wait+0x2a7/frame
0xfffffe2020ebc320
__mtx_lock_sleep() at 0xffffffff80484d9d = __mtx_lock_sleep+0x13d/frame
0xfffffe2020ebc3a0
soalloc() at 0xffffffff8051b914 = soalloc+0x1b4/frame 0xfffffe2020ebc3f0
sonewconn() at 0xffffffff8051bb9f = sonewconn+0xbf/frame 0xfffffe2020ebc430
syncache_expand() at 0xffffffff8061b85b = syncache_expand+0x78b/frame
0xfffffe2020ebc590
tcp_input() at 0xffffffff8060e10e = tcp_input+0xdae/frame 0xfffffe2020ebc6e0
ip_input() at 0xffffffff805a087f = ip_input+0x15f/frame 0xfffffe2020ebc740
netisr_dispatch_src() at 0xffffffff80583db5 = netisr_dispatch_src+0xa5/frame
0xfffffe2020ebc7a0
ether_demux() at 0xffffffff80575b3a = ether_demux+0x12a/frame 0xfffffe2020ebc7d0
ether_nh_input() at 0xffffffff80576792 = ether_nh_input+0x322/frame
0xfffffe2020ebc830
netisr_dispatch_src() at 0xffffffff80583db5 = netisr_dispatch_src+0xa5/frame
0xfffffe2020ebc890
ether_input() at 0xffffffff80575db6 = ether_input+0x26/frame 0xfffffe2020ebc8b0
ixgbe_rxeof() at 0xffffffff813df36b = ixgbe_rxeof+0x7ab/frame 0xfffffe2020ebc990
ixgbe_msix_que() at 0xffffffff813da57c = ixgbe_msix_que+0x8c/frame
0xfffffe2020ebc9e0
intr_event_execute_handlers() at 0xffffffff8046c605 =
intr_event_execute_handlers+0x95/frame 0xfffffe2020ebca20
ithread_loop() at 0xffffffff8046cc26 = ithread_loop+0xa6/frame
0xfffffe2020ebca70
fork_exit() at 0xffffffff8046a211 = fork_exit+0x71/frame 0xfffffe2020ebcab0
fork_trampoline() at 0xffffffff806cb50e = fork_trampoline+0xe/frame
0xfffffe2020ebcab0
--- trap 0, rip = 0, rsp = 0, rbp = 0 ---
Tracing command intr pid 12 tid 100111 td 0xfffff801250a2000
sched_switch() at 0xffffffff804c956d = sched_switch+0x6ad/frame
0xfffffe2020f302f0
mi_switch() at 0xffffffff804a8d92 = mi_switch+0xd2/frame 0xfffffe2020f30320
turnstile_wait() at 0xffffffff804ef177 = turnstile_wait+0x2a7/frame
0xfffffe2020f30360
__mtx_lock_sleep() at 0xffffffff80484d9d = __mtx_lock_sleep+0x13d/frame
0xfffffe2020f303e0
sodealloc() at 0xffffffff8051b992 = sodealloc+0x32/frame 0xfffffe2020f30420
tcp_close() at 0xffffffff80618150 = tcp_close+0xd0/frame 0xfffffe2020f30450
tcp_twstart() at 0xffffffff8061f0e7 = tcp_twstart+0x2b7/frame 0xfffffe2020f30490
tcp_do_segment() at 0xffffffff80610bdf = tcp_do_segment+0x201f/frame
0xfffffe2020f30590
tcp_input() at 0xffffffff8060e17c = tcp_input+0xe1c/frame 0xfffffe2020f306e0
ip_input() at 0xffffffff805a087f = ip_input+0x15f/frame 0xfffffe2020f30740
netisr_dispatch_src() at 0xffffffff80583db5 = netisr_dispatch_src+0xa5/frame
0xfffffe2020f307a0
ether_demux() at 0xffffffff80575b3a = ether_demux+0x12a/frame 0xfffffe2020f307d0
ether_nh_input() at 0xffffffff80576792 = ether_nh_input+0x322/frame
0xfffffe2020f30830
netisr_dispatch_src() at 0xffffffff80583db5 = netisr_dispatch_src+0xa5/frame
0xfffffe2020f30890
ether_input() at 0xffffffff80575db6 = ether_input+0x26/frame 0xfffffe2020f308b0
ixgbe_rxeof() at 0xffffffff813df36b = ixgbe_rxeof+0x7ab/frame 0xfffffe2020f30990
ixgbe_msix_que() at 0xffffffff813da57c = ixgbe_msix_que+0x8c/frame
0xfffffe2020f309e0
intr_event_execute_handlers() at 0xffffffff8046c605 =
intr_event_execute_handlers+0x95/frame 0xfffffe2020f30a20
ithread_loop() at 0xffffffff8046cc26 = ithread_loop+0xa6/frame
0xfffffe2020f30a70
fork_exit() at 0xffffffff8046a211 = fork_exit+0x71/frame 0xfffffe2020f30ab0
fork_trampoline() at 0xffffffff806cb50e = fork_trampoline+0xe/frame
0xfffffe2020f30ab0
--- trap 0, rip = 0, rsp = 0, rbp = 0 ---
Tracing command intr pid 12 tid 100113 td 0xfffff801250a1500
sched_switch() at 0xffffffff804c956d = sched_switch+0x6ad/frame
0xfffffe2020f3a2f0
mi_switch() at 0xffffffff804a8d92 = mi_switch+0xd2/frame 0xfffffe2020f3a320
turnstile_wait() at 0xffffffff804ef177 = turnstile_wait+0x2a7/frame
0xfffffe2020f3a360
__mtx_lock_sleep() at 0xffffffff80484d9d = __mtx_lock_sleep+0x13d/frame
0xfffffe2020f3a3e0
sodealloc() at 0xffffffff8051b992 = sodealloc+0x32/frame 0xfffffe2020f3a420
tcp_close() at 0xffffffff80618150 = tcp_close+0xd0/frame 0xfffffe2020f3a450
tcp_twstart() at 0xffffffff8061f0e7 = tcp_twstart+0x2b7/frame 0xfffffe2020f3a490
tcp_do_segment() at 0xffffffff80610bdf = tcp_do_segment+0x201f/frame
0xfffffe2020f3a590
tcp_input() at 0xffffffff8060e17c = tcp_input+0xe1c/frame 0xfffffe2020f3a6e0
ip_input() at 0xffffffff805a087f = ip_input+0x15f/frame 0xfffffe2020f3a740
netisr_dispatch_src() at 0xffffffff80583db5 = netisr_dispatch_src+0xa5/frame
0xfffffe2020f3a7a0
ether_demux() at 0xffffffff80575b3a = ether_demux+0x12a/frame 0xfffffe2020f3a7d0
ether_nh_input() at 0xffffffff80576792 = ether_nh_input+0x322/frame
0xfffffe2020f3a830
netisr_dispatch_src() at 0xffffffff80583db5 = netisr_dispatch_src+0xa5/frame
0xfffffe2020f3a890
ether_input() at 0xffffffff80575db6 = ether_input+0x26/frame 0xfffffe2020f3a8b0
ixgbe_rxeof() at 0xffffffff813df36b = ixgbe_rxeof+0x7ab/frame 0xfffffe2020f3a990
ixgbe_msix_que() at 0xffffffff813da57c = ixgbe_msix_que+0x8c/frame
0xfffffe2020f3a9e0
intr_event_execute_handlers() at 0xffffffff8046c605 =
intr_event_execute_handlers+0x95/frame 0xfffffe2020f3aa20
ithread_loop() at 0xffffffff8046cc26 = ithread_loop+0xa6/frame
0xfffffe2020f3aa70
fork_exit() at 0xffffffff8046a211 = fork_exit+0x71/frame 0xfffffe2020f3aab0
fork_trampoline() at 0xffffffff806cb50e = fork_trampoline+0xe/frame
0xfffffe2020f3aab0
--- trap 0, rip = 0, rsp = 0, rbp = 0 ---
Tracing command intr pid 12 tid 100115 td 0xfffff801250a0a00
cpustop_handler() at 0xffffffff80775998 = cpustop_handler+0x28/frame
0xfffffe1f9e182cf0
ipi_nmi_handler() at 0xffffffff8077595a = ipi_nmi_handler+0x4a/frame
0xfffffe1f9e182d10
trap() at 0xffffffff806e2e4a = trap+0x3a/frame 0xfffffe1f9e182f20
nmi_calltrap() at 0xffffffff806cb413 = nmi_calltrap+0x8/frame 0xfffffe1f9e182f20
--- trap 0x13, rip = 0xffffffff8059b9f9, rsp = 0xfffffe2020f44420, rbp =
0xfffffe2020f44420 ---
in_pcbref() at 0xffffffff8059b9f9 = in_pcbref+0x9/frame 0xfffffe2020f44420
tcp_tw_2msl_scan() at 0xffffffff8061f1a3 = tcp_tw_2msl_scan+0x73/frame
0xfffffe2020f44450
tcp_twstart() at 0xffffffff8061eed3 = tcp_twstart+0xa3/frame 0xfffffe2020f44490
tcp_do_segment() at 0xffffffff80610bdf = tcp_do_segment+0x201f/frame
0xfffffe2020f44590
tcp_input() at 0xffffffff8060e17c = tcp_input+0xe1c/frame 0xfffffe2020f446e0
ip_input() at 0xffffffff805a087f = ip_input+0x15f/frame 0xfffffe2020f44740
netisr_dispatch_src() at 0xffffffff80583db5 = netisr_dispatch_src+0xa5/frame
0xfffffe2020f447a0
ether_demux() at 0xffffffff80575b3a = ether_demux+0x12a/frame 0xfffffe2020f447d0
ether_nh_input() at 0xffffffff80576792 = ether_nh_input+0x322/frame
0xfffffe2020f44830
netisr_dispatch_src() at 0xffffffff80583db5 = netisr_dispatch_src+0xa5/frame
0xfffffe2020f44890
ether_input() at 0xffffffff80575db6 = ether_input+0x26/frame 0xfffffe2020f448b0
ixgbe_rxeof() at 0xffffffff813df36b = ixgbe_rxeof+0x7ab/frame 0xfffffe2020f44990
ixgbe_msix_que() at 0xffffffff813da57c = ixgbe_msix_que+0x8c/frame
0xfffffe2020f449e0
intr_event_execute_handlers() at 0xffffffff8046c605 =
intr_event_execute_handlers+0x95/frame 0xfffffe2020f44a20
ithread_loop() at 0xffffffff8046cc26 = ithread_loop+0xa6/frame
0xfffffe2020f44a70
fork_exit() at 0xffffffff8046a211 = fork_exit+0x71/frame 0xfffffe2020f44ab0
fork_trampoline() at 0xffffffff806cb50e = fork_trampoline+0xe/frame
0xfffffe2020f44ab0
--- trap 0, rip = 0, rsp = 0, rbp = 0 ---
Tracing command ps pid 37011 tid 101992 td 0xfffff80144378000
sched_switch() at 0xffffffff804c956d = sched_switch+0x6ad/frame
0xfffffe20224367b0
mi_switch() at 0xffffffff804a8d92 = mi_switch+0xd2/frame 0xfffffe20224367e0
turnstile_wait() at 0xffffffff804ef177 = turnstile_wait+0x2a7/frame
0xfffffe2022436820
__mtx_lock_sleep() at 0xffffffff80484d9d = __mtx_lock_sleep+0x13d/frame
0xfffffe20224368a0
soalloc() at 0xffffffff8051b914 = soalloc+0x1b4/frame 0xfffffe20224368f0
socreate() at 0xffffffff8051b617 = socreate+0xa7/frame 0xfffffe2022436940
sys_socket() at 0xffffffff8052144d = sys_socket+0xed/frame 0xfffffe20224369a0
amd64_syscall() at 0xffffffff806e4051 = amd64_syscall+0x2c1/frame
0xfffffe2022436ab0
Xfast_syscall() at 0xffffffff806cb2bb = Xfast_syscall+0xfb/frame
0xfffffe2022436ab0
--- syscall (97, FreeBSD ELF64, sys_socket), rip = 0x8011c413a, rsp =
0x7fffffffc748, rbp = 0x7fffffffc770 ---
Tracing command cron pid 37008 tid 102228 td 0xfffff801a4090000
sched_switch() at 0xffffffff804c956d = sched_switch+0x6ad/frame
0xfffffe20228d67b0
mi_switch() at 0xffffffff804a8d92 = mi_switch+0xd2/frame 0xfffffe20228d67e0
turnstile_wait() at 0xffffffff804ef177 = turnstile_wait+0x2a7/frame
0xfffffe20228d6820
__mtx_lock_sleep() at 0xffffffff80484d9d = __mtx_lock_sleep+0x13d/frame
0xfffffe20228d68a0
soalloc() at 0xffffffff8051b914 = soalloc+0x1b4/frame 0xfffffe20228d68f0
socreate() at 0xffffffff8051b617 = socreate+0xa7/frame 0xfffffe20228d6940
sys_socket() at 0xffffffff8052144d = sys_socket+0xed/frame 0xfffffe20228d69a0
amd64_syscall() at 0xffffffff806e4051 = amd64_syscall+0x2c1/frame
0xfffffe20228d6ab0
Xfast_syscall() at 0xffffffff806cb2bb = Xfast_syscall+0xfb/frame
0xfffffe20228d6ab0
--- syscall (97, FreeBSD ELF64, sys_socket), rip = 0x800d8c13a, rsp =
0x7fffffffd658, rbp = 0x7fffffffd6f0 ---
[many likes]
Tracing command intr pid 12 tid 100015 td 0xfffff8011422b000
sched_switch() at 0xffffffff804c956d = sched_switch+0x6ad/frame
0xfffffe1f9e1cf760
mi_switch() at 0xffffffff804a8d92 = mi_switch+0xd2/frame 0xfffffe1f9e1cf790
turnstile_wait() at 0xffffffff804ef177 = turnstile_wait+0x2a7/frame
0xfffffe1f9e1cf7d0
__mtx_lock_sleep() at 0xffffffff80484d9d = __mtx_lock_sleep+0x13d/frame
0xfffffe1f9e1cf850
sodealloc() at 0xffffffff8051b992 = sodealloc+0x32/frame 0xfffffe1f9e1cf890
tcp_close() at 0xffffffff80618150 = tcp_close+0xd0/frame 0xfffffe1f9e1cf8c0
tcp_timer_2msl() at 0xffffffff8061dda3 = tcp_timer_2msl+0x1f3/frame
0xfffffe1f9e1cf8f0
softclock_call_cc() at 0xffffffff804b4ca9 = softclock_call_cc+0x179/frame
0xfffffe1f9e1cf9c0
softclock() at 0xffffffff804b5034 = softclock+0x44/frame 0xfffffe1f9e1cf9e0
intr_event_execute_handlers() at 0xffffffff8046c605 =
intr_event_execute_handlers+0x95/frame 0xfffffe1f9e1cfa20
ithread_loop() at 0xffffffff8046cc26 = ithread_loop+0xa6/frame
0xfffffe1f9e1cfa70
fork_exit() at 0xffffffff8046a211 = fork_exit+0x71/frame 0xfffffe1f9e1cfab0
fork_trampoline() at 0xffffffff806cb50e = fork_trampoline+0xe/frame
0xfffffe1f9e1cfab0
--- trap 0, rip = 0, rsp = 0, rbp = 0 ---
Tracing command intr pid 12 tid 100016 td 0xfffff8011422aa00
sched_switch() at 0xffffffff804c956d = sched_switch+0x6ad/frame
0xfffffe1f9e1d4760
mi_switch() at 0xffffffff804a8d92 = mi_switch+0xd2/frame 0xfffffe1f9e1d4790
turnstile_wait() at 0xffffffff804ef177 = turnstile_wait+0x2a7/frame
0xfffffe1f9e1d47d0
__mtx_lock_sleep() at 0xffffffff80484d9d = __mtx_lock_sleep+0x13d/frame
0xfffffe1f9e1d4850
sodealloc() at 0xffffffff8051b992 = sodealloc+0x32/frame 0xfffffe1f9e1d4890
tcp_close() at 0xffffffff80618150 = tcp_close+0xd0/frame 0xfffffe1f9e1d48c0
tcp_timer_2msl() at 0xffffffff8061dda3 = tcp_timer_2msl+0x1f3/frame
0xfffffe1f9e1d48f0
softclock_call_cc() at 0xffffffff804b4ca9 = softclock_call_cc+0x179/frame
0xfffffe1f9e1d49c0
softclock() at 0xffffffff804b5034 = softclock+0x44/frame 0xfffffe1f9e1d49e0
intr_event_execute_handlers() at 0xffffffff8046c605 =
intr_event_execute_handlers+0x95/frame 0xfffffe1f9e1d4a20
ithread_loop() at 0xffffffff8046cc26 = ithread_loop+0xa6/frame
0xfffffe1f9e1d4a70
fork_exit() at 0xffffffff8046a211 = fork_exit+0x71/frame 0xfffffe1f9e1d4ab0
fork_trampoline() at 0xffffffff806cb50e = fork_trampoline+0xe/frame
0xfffffe1f9e1d4ab0
--- trap 0, rip = 0, rsp = 0, rbp = 0 ---
Tracing command intr pid 12 tid 100017 td 0xfffff8011422a500
sched_switch() at 0xffffffff804c956d = sched_switch+0x6ad/frame
0xfffffe1f9e1d9760
mi_switch() at 0xffffffff804a8d92 = mi_switch+0xd2/frame 0xfffffe1f9e1d9790
turnstile_wait() at 0xffffffff804ef177 = turnstile_wait+0x2a7/frame
0xfffffe1f9e1d97d0
__mtx_lock_sleep() at 0xffffffff80484d9d = __mtx_lock_sleep+0x13d/frame
0xfffffe1f9e1d9850
sodealloc() at 0xffffffff8051b992 = sodealloc+0x32/frame 0xfffffe1f9e1d9890
tcp_close() at 0xffffffff80618150 = tcp_close+0xd0/frame 0xfffffe1f9e1d98c0
tcp_timer_2msl() at 0xffffffff8061dda3 = tcp_timer_2msl+0x1f3/frame
0xfffffe1f9e1d98f0
softclock_call_cc() at 0xffffffff804b4ca9 = softclock_call_cc+0x179/frame
0xfffffe1f9e1d99c0
softclock() at 0xffffffff804b5034 = softclock+0x44/frame 0xfffffe1f9e1d99e0
intr_event_execute_handlers() at 0xffffffff8046c605 =
intr_event_execute_handlers+0x95/frame 0xfffffe1f9e1d9a20
ithread_loop() at 0xffffffff8046cc26 = ithread_loop+0xa6/frame
0xfffffe1f9e1d9a70
fork_exit() at 0xffffffff8046a211 = fork_exit+0x71/frame 0xfffffe1f9e1d9ab0
fork_trampoline() at 0xffffffff806cb50e = fork_trampoline+0xe/frame
0xfffffe1f9e1d9ab0
--- trap 0, rip = 0, rsp = 0, rbp = 0 ---
Tracing command intr pid 12 tid 100018 td 0xfffff8011422a000
sched_switch() at 0xffffffff804c956d = sched_switch+0x6ad/frame
0xfffffe1f9e1de760
mi_switch() at 0xffffffff804a8d92 = mi_switch+0xd2/frame 0xfffffe1f9e1de790
turnstile_wait() at 0xffffffff804ef177 = turnstile_wait+0x2a7/frame
0xfffffe1f9e1de7d0
__mtx_lock_sleep() at 0xffffffff80484d9d = __mtx_lock_sleep+0x13d/frame
0xfffffe1f9e1de850
sodealloc() at 0xffffffff8051b992 = sodealloc+0x32/frame 0xfffffe1f9e1de890
tcp_close() at 0xffffffff80618150 = tcp_close+0xd0/frame 0xfffffe1f9e1de8c0
tcp_timer_2msl() at 0xffffffff8061dda3 = tcp_timer_2msl+0x1f3/frame
0xfffffe1f9e1de8f0
softclock_call_cc() at 0xffffffff804b4ca9 = softclock_call_cc+0x179/frame
0xfffffe1f9e1de9c0
softclock() at 0xffffffff804b5034 = softclock+0x44/frame 0xfffffe1f9e1de9e0
intr_event_execute_handlers() at 0xffffffff8046c605 =
intr_event_execute_handlers+0x95/frame 0xfffffe1f9e1dea20
ithread_loop() at 0xffffffff8046cc26 = ithread_loop+0xa6/frame
0xfffffe1f9e1dea70
fork_exit() at 0xffffffff8046a211 = fork_exit+0x71/frame 0xfffffe1f9e1deab0
fork_trampoline() at 0xffffffff806cb50e = fork_trampoline+0xe/frame
0xfffffe1f9e1deab0
--- trap 0, rip = 0, rsp = 0, rbp = 0 ---
Tracing command intr pid 12 tid 100019 td 0xfffff8011424da00
sched_switch() at 0xffffffff804c956d = sched_switch+0x6ad/frame
0xfffffe1f9e1e3760
mi_switch() at 0xffffffff804a8d92 = mi_switch+0xd2/frame 0xfffffe1f9e1e3790
turnstile_wait() at 0xffffffff804ef177 = turnstile_wait+0x2a7/frame
0xfffffe1f9e1e37d0
__mtx_lock_sleep() at 0xffffffff80484d9d = __mtx_lock_sleep+0x13d/frame
0xfffffe1f9e1e3850
sodealloc() at 0xffffffff8051b992 = sodealloc+0x32/frame 0xfffffe1f9e1e3890
tcp_close() at 0xffffffff80618150 = tcp_close+0xd0/frame 0xfffffe1f9e1e38c0
tcp_timer_2msl() at 0xffffffff8061dda3 = tcp_timer_2msl+0x1f3/frame
0xfffffe1f9e1e38f0
softclock_call_cc() at 0xffffffff804b4ca9 = softclock_call_cc+0x179/frame
0xfffffe1f9e1e39c0
softclock() at 0xffffffff804b5034 = softclock+0x44/frame 0xfffffe1f9e1e39e0
intr_event_execute_handlers() at 0xffffffff8046c605 = intr_event_execute-- 7:zsh
-- time-stamp -- Sep/26/16 20:00:13 --
-- 7:zsh -- time-stamp -- Sep/26/16 20:00:13 --
_handlers+0x95/frame 0xfffffe1f9e1e3a20
ithread_loop() at 0xffffffff8046cc26 = ithread_loop+0xa6/frame
0xfffffe1f9e1e3a70
fork_exit() at 0xffffffff8046a211 = fork_exit+0x71/frame 0xfffffe1f9e1e3ab0
fork_trampoline() at 0xffffffff806cb50e = fork_trampoline+0xe/frame
0xfffffe1f9e1e3ab0
--- trap 0, rip = 0, rsp = 0, rbp = 0 ---
Tracing command intr pid 12 tid 100020 td 0xfffff8011424d500
sched_switch() at 0xffffffff804c956d = sched_switch+0x6ad/frame
0xfffffe1f9e1e8760
mi_switch() at 0xffffffff804a8d92 = mi_switch+0xd2/frame 0xfffffe1f9e1e8790
turnstile_wait() at 0xffffffff804ef177 = turnstile_wait+0x2a7/frame
0xfffffe1f9e1e87d0
__mtx_lock_sleep() at 0xffffffff80484d9d = __mtx_lock_sleep+0x13d/frame
0xfffffe1f9e1e8850
sodealloc() at 0xffffffff8051b992 = sodealloc+0x32/frame 0xfffffe1f9e1e8890
tcp_close() at 0xffffffff80618150 = tcp_close+0xd0/frame 0xfffffe1f9e1e88c0
tcp_timer_2msl() at 0xffffffff8061dda3 = tcp_timer_2msl+0x1f3/frame
0xfffffe1f9e1e88f0
softclock_call_cc() at 0xffffffff804b4ca9 = softclock_call_cc+0x179/frame
0xfffffe1f9e1e89c0
softclock() at 0xffffffff804b5034 = softclock+0x44/frame 0xfffffe1f9e1e89e0
intr_event_execute_handlers() at 0xffffffff8046c605 =
intr_event_execute_handlers+0x95/frame 0xfffffe1f9e1e8a20
ithread_loop() at 0xffffffff8046cc26 = ithread_loop+0xa6/frame
0xfffffe1f9e1e8a70
fork_exit() at 0xffffffff8046a211 = fork_exit+0x71/frame 0xfffffe1f9e1e8ab0
fork_trampoline() at 0xffffffff806cb50e = fork_trampoline+0xe/frame
0xfffffe1f9e1e8ab0
--- trap 0, rip = 0, rsp = 0, rbp = 0 ---
Tracing command intr pid 12 tid 100021 td 0xfffff8011424d000
sched_switch() at 0xffffffff804c956d = sched_switch+0x6ad/frame
0xfffffe1f9e1ed760
mi_switch() at 0xffffffff804a8d92 = mi_switch+0xd2/frame 0xfffffe1f9e1ed790
turnstile_wait() at 0xffffffff804ef177 = turnstile_wait+0x2a7/frame
0xfffffe1f9e1ed7d0
__mtx_lock_sleep() at 0xffffffff80484d9d = __mtx_lock_sleep+0x13d/frame
0xfffffe1f9e1ed850
sodealloc() at 0xffffffff8051b992 = sodealloc+0x32/frame 0xfffffe1f9e1ed890
tcp_close() at 0xffffffff80618150 = tcp_close+0xd0/frame 0xfffffe1f9e1ed8c0
tcp_timer_2msl() at 0xffffffff8061dda3 = tcp_timer_2msl+0x1f3/frame
0xfffffe1f9e1ed8f0
softclock_call_cc() at 0xffffffff804b4ca9 = softclock_call_cc+0x179/frame
0xfffffe1f9e1ed9c0
softclock() at 0xffffffff804b5034 = softclock+0x44/frame 0xfffffe1f9e1ed9e0
intr_event_execute_handlers() at 0xffffffff8046c605 =
intr_event_execute_handlers+0x95/frame 0xfffffe1f9e1eda20
ithread_loop() at 0xffffffff8046cc26 = ithread_loop+0xa6/frame
0xfffffe1f9e1eda70
fork_exit() at 0xffffffff8046a211 = fork_exit+0x71/frame 0xfffffe1f9e1edab0
fork_trampoline() at 0xffffffff806cb50e = fork_trampoline+0xe/frame
0xfffffe1f9e1edab0
--- trap 0, rip = 0, rsp = 0, rbp = 0 ---
Tracing command intr pid 12 tid 100022 td 0xfffff8011424ca00
sched_switch() at 0xffffffff804c956d = sched_switch+0x6ad/frame
0xfffffe1f9e1f2760
mi_switch() at 0xffffffff804a8d92 = mi_switch+0xd2/frame 0xfffffe1f9e1f2790
turnstile_wait() at 0xffffffff804ef177 = turnstile_wait+0x2a7/frame
0xfffffe1f9e1f27d0
__mtx_lock_sleep() at 0xffffffff80484d9d = __mtx_lock_sleep+0x13d/frame
0xfffffe1f9e1f2850
sodealloc() at 0xffffffff8051b992 = sodealloc+0x32/frame 0xfffffe1f9e1f2890
tcp_close() at 0xffffffff80618150 = tcp_close+0xd0/frame 0xfffffe1f9e1f28c0
tcp_timer_2msl() at 0xffffffff8061dda3 = tcp_timer_2msl+0x1f3/frame
0xfffffe1f9e1f28f0
softclock_call_cc() at 0xffffffff804b4ca9 = softclock_call_cc+0x179/frame
0xfffffe1f9e1f29c0
softclock() at 0xffffffff804b5034 = softclock+0x44/frame 0xfffffe1f9e1f29e0
intr_event_execute_handlers() at 0xffffffff8046c605 =
intr_event_execute_handlers+0x95/frame 0xfffffe1f9e1f2a20
ithread_loop() at 0xffffffff8046cc26 = ithread_loop+0xa6/frame
0xfffffe1f9e1f2a70
fork_exit() at 0xffffffff8046a211 = fork_exit+0x71/frame 0xfffffe1f9e1f2ab0
fork_trampoline() at 0xffffffff806cb50e = fork_trampoline+0xe/frame
0xfffffe1f9e1f2ab0
--- trap 0, rip = 0, rsp = 0, rbp = 0 ---
Tracing command intr pid 12 tid 100023 td 0xfffff8011424c500
sched_switch() at 0xffffffff804c956d = sched_switch+0x6ad/frame
0xfffffe1f9e1f7760
mi_switch() at 0xffffffff804a8d92 = mi_switch+0xd2/frame 0xfffffe1f9e1f7790
turnstile_wait() at 0xffffffff804ef177 = turnstile_wait+0x2a7/frame
0xfffffe1f9e1f77d0
__mtx_lock_sleep() at 0xffffffff80484d9d = __mtx_lock_sleep+0x13d/frame
0xfffffe1f9e1f7850
sodealloc() at 0xffffffff8051b992 = sodealloc+0x32/frame 0xfffffe1f9e1f7890
tcp_close() at 0xffffffff80618150 = tcp_close+0xd0/frame 0xfffffe1f9e1f78c0
tcp_timer_rexmt() at 0xffffffff8061e454 = tcp_timer_rexmt+0x114/frame
0xfffffe1f9e1f78f0
softclock_call_cc() at 0xffffffff804b4ca9 = softclock_call_cc+0x179/frame
0xfffffe1f9e1f79c0
softclock() at 0xffffffff804b5034 = softclock+0x44/frame 0xfffffe1f9e1f79e0
intr_event_execute_handlers() at 0xffffffff8046c605 =
intr_event_execute_handlers+0x95/frame 0xfffffe1f9e1f7a20
ithread_loop() at 0xffffffff8046cc26 = ithread_loop+0xa6/frame
0xfffffe1f9e1f7a70
fork_exit() at 0xffffffff8046a211 = fork_exit+0x71/frame 0xfffffe1f9e1f7ab0
fork_trampoline() at 0xffffffff806cb50e = fork_trampoline+0xe/frame
0xfffffe1f9e1f7ab0
--- trap 0, rip = 0, rsp = 0, rbp = 0 ---
Tracing command intr pid 12 tid 100024 td 0xfffff8011424c000
sched_switch() at 0xffffffff804c956d = sched_switch+0x6ad/frame
0xfffffe1f9e1fc760
mi_switch() at 0xffffffff804a8d92 = mi_switch+0xd2/frame 0xfffffe1f9e1fc790
turnstile_wait() at 0xffffffff804ef177 = turnstile_wait+0x2a7/frame
0xfffffe1f9e1fc7d0
__mtx_lock_sleep() at 0xffffffff80484d9d = __mtx_lock_sleep+0x13d/frame
0xfffffe1f9e1fc850
sodealloc() at 0xffffffff8051b992 = sodealloc+0x32/frame 0xfffffe1f9e1fc890
tcp_close() at 0xffffffff80618150 = tcp_close+0xd0/frame 0xfffffe1f9e1fc8c0
tcp_timer_2msl() at 0xffffffff8061dda3 = tcp_timer_2msl+0x1f3/frame
0xfffffe1f9e1fc8f0
softclock_call_cc() at 0xffffffff804b4ca9 = softclock_call_cc+0x179/frame
0xfffffe1f9e1fc9c0
softclock() at 0xffffffff804b5034 = softclock+0x44/frame 0xfffffe1f9e1fc9e0
intr_event_execute_handlers() at 0xffffffff8046c605 =
intr_event_execute_handlers+0x95/frame 0xfffffe1f9e1fca20
ithread_loop() at 0xffffffff8046cc26 = ithread_loop+0xa6/frame
0xfffffe1f9e1fca70
fork_exit() at 0xffffffff8046a211 = fork_exit+0x71/frame 0xfffffe1f9e1fcab0
fork_trampoline() at 0xffffffff806cb50e = fork_trampoline+0xe/frame
0xfffffe1f9e1fcab0
--- trap 0, rip = 0, rsp = 0, rbp = 0 ---
Tracing command intr pid 12 tid 100025 td 0xfffff8011424ba00
sched_switch() at 0xffffffff804c956d = sched_switch+0x6ad/frame
0xfffffe0000382760
mi_switch() at 0xffffffff804a8d92 = mi_switch+0xd2/frame 0xfffffe0000382790
turnstile_wait() at 0xffffffff804ef177 = turnstile_wait+0x2a7/frame
0xfffffe00003827d0
__mtx_lock_sleep() at 0xffffffff80484d9d = __mtx_lock_sleep+0x13d/frame
0xfffffe0000382850
sodealloc() at 0xffffffff8051b992 = sodealloc+0x32/frame 0xfffffe0000382890
tcp_close() at 0xffffffff80618150 = tcp_close+0xd0/frame 0xfffffe00003828c0
tcp_timer_2msl() at 0xffffffff8061dda3 = tcp_timer_2msl+0x1f3/frame
0xfffffe00003828f0
softclock_call_cc() at 0xffffffff804b4ca9 = softclock_call_cc+0x179/frame
0xfffffe00003829c0
softclock() at 0xffffffff804b5034 = softclock+0x44/frame 0xfffffe00003829e0
intr_event_execute_handlers() at 0xffffffff8046c605 =
intr_event_execute_handlers+0x95/frame 0xfffffe0000382a20
ithread_loop() at 0xffffffff8046cc26 = ithread_loop+0xa6/frame
0xfffffe0000382a70
fork_exit() at 0xffffffff8046a211 = fork_exit+0x71/frame 0xfffffe0000382ab0
fork_trampoline() at 0xffffffff806cb50e = fork_trampoline+0xe/frame
0xfffffe0000382ab0
--- trap 0, rip = 0, rsp = 0, rbp = 0 ---
Tracing command intr pid 12 tid 100026 td 0xfffff8011424b500
sched_switch() at 0xffffffff804c956d = sched_switch+0x6ad/frame
0xfffffe00003876f0
mi_switch() at 0xffffffff804a8d92 = mi_switch+0xd2/frame 0xfffffe0000387720
critical_exit() at 0xffffffff804a6bee = critical_exit+0x7e/frame
0xfffffe0000387740
ipi_bitmap_handler() at 0xffffffff80775629 = ipi_bitmap_handler+0x79/frame
0xfffffe0000387780
Xipi_intr_bitmap_handler() at 0xffffffff806cc15e =
Xipi_intr_bitmap_handler+0x8e/frame 0xfffffe0000387780
--- interrupt, rip = 0xffffffff80484c1f, rsp = 0xfffffe0000387850, rbp =
0xfffffe0000387850 ---
__mtx_lock_flags() at 0xffffffff80484c1f = __mtx_lock_flags+0x2f/frame
0xfffffe0000387850
sodealloc() at 0xffffffff8051b992 = sodealloc+0x32/frame 0xfffffe0000387890
tcp_close() at 0xffffffff80618150 = tcp_close+0xd0/frame 0xfffffe00003878c0
tcp_timer_2msl() at 0xffffffff8061dda3 = tcp_timer_2msl+0x1f3/frame
0xfffffe00003878f0
softclock_call_cc() at 0xffffffff804b4ca9 = softclock_call_cc+0x179/frame
0xfffffe00003879c0
softclock() at 0xffffffff804b5034 = softclock+0x44/frame 0xfffffe00003879e0
intr_event_execute_handlers() at 0xffffffff8046c605 =
intr_event_execute_handlers+0x95/frame 0xfffffe0000387a20
ithread_loop() at 0xffffffff8046cc26 = ithread_loop+0xa6/frame
0xfffffe0000387a70
fork_exit() at 0xffffffff8046a211 = fork_exit+0x71/frame 0xfffffe0000387ab0
fork_trampoline() at 0xffffffff806cb50e = fork_trampoline+0xe/frame
0xfffffe0000387ab0
--- trap 0, rip = 0, rsp = 0, rbp = 0 ---