Hi Slawa, On 9/26/16 7:22 PM, Slawa Olhovchenkov wrote:> On Mon, Sep 26, 2016 at 11:33:12AM +0200, Julien Charbon wrote: >> 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 ---Nice stack traces, all threads are blocked in sodealloc() or soalloc() and if you look at how mtx_lock(&so_global_mtx) and mtx_unlock(&so_global_mtx) are used, it is hard to think about a scenario that can lead to this state. I am still trying to reproduce your issue, without success so far. -- Julien -------------- next part -------------- A non-text attachment was scrubbed... Name: signature.asc Type: application/pgp-signature Size: 496 bytes Desc: OpenPGP digital signature URL: <http://lists.freebsd.org/pipermail/freebsd-stable/attachments/20160928/ad00348b/attachment.sig>
On Wed, Sep 28, 2016 at 12:06:47PM +0200, Julien Charbon wrote:> > 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 --- > > Nice stack traces, all threads are blocked in sodealloc() or soalloc() > and if you look at how mtx_lock(&so_global_mtx) and > mtx_unlock(&so_global_mtx) are used, it is hard to think about a > scenario that can lead to this state. > > I am still trying to reproduce your issue, without success so far.May be some hardware-related (low-speed CPU?). Yesternight I am collect new stack traces and kernel dump. May be I can see something? db> ps pid ppid pgrp uid state wmesg wchan cmd 12 0 0 0 RL (threaded) [intr] 100023 RunQ [swi4: clock (8)] 100107 Run CPU 8 [irq291: ix0:q2] 11 0 0 0 RL (threaded) [idle] 100011 CanRun [idle: cpu8] cpuid = 8 dynamic pcpu = 0xfffffe201d69cf00 curthread = 0xfffff8012508d500: pid 12 "irq291: ix0:q2" curpcb = 0xfffffe2020ebcb80 fpcurthread = none idlethread = 0xfffff8011422c500: tid 100011 "idle: cpu8" curpmap = 0xffffffff80d49998 tssp = 0xffffffff80d7fcd0 commontssp = 0xffffffff80d7fcd0 rsp0 = 0xfffffe2020ebcb80 gs32p = 0xffffffff80d86528 ldt = 0xffffffff80d86568 tss = 0xffffffff80d86558 Tracing command nginx pid 1061 tid 101747 td 0xfffff8014b35b500 sched_switch() at 0xffffffff804c956d = sched_switch+0x6ad/frame 0xfffffe2021b70330 mi_switch() at 0xffffffff804a8d92 = mi_switch+0xd2/frame 0xfffffe2021b70360 turnstile_wait() at 0xffffffff804ef177 = turnstile_wait+0x2a7/frame 0xfffffe2021b703a0 __rw_wlock_hard() at 0xffffffff8049c314 = __rw_wlock_hard+0x94/frame 0xfffffe2021b70430 in_lltable_lookup() at 0xffffffff80594823 = in_lltable_lookup+0x83/frame 0xfffffe2021b70450 arpresolve() at 0xffffffff8058d2aa = arpresolve+0x9a/frame 0xfffffe2021b704b0 ether_output() at 0xffffffff805755e2 = ether_output+0x2f2/frame 0xfffffe2021b70550 ip_output() at 0xffffffff805a4200 = ip_output+0x1390/frame 0xfffffe2021b706b0 tcp_output() at 0xffffffff806149d5 = tcp_output+0x17a5/frame 0xfffffe2021b70850 tcp_usr_disconnect() at 0xffffffff80620094 = tcp_usr_disconnect+0x74/frame 0xfffffe2021b70880 soclose() at 0xffffffff8051c238 = soclose+0x38/frame 0xfffffe2021b708b0 _fdrop() at 0xffffffff8045639a = _fdrop+0x1a/frame 0xfffffe2021b708d0 closef() at 0xffffffff80458a53 = closef+0x1e3/frame 0xfffffe2021b70960 closefp() at 0xffffffff804567ad = closefp+0x7d/frame 0xfffffe2021b709a0 amd64_syscall() at 0xffffffff806e4051 = amd64_syscall+0x2c1/frame 0xfffffe2021b70ab0 Xfast_syscall() at 0xffffffff806cb2bb = Xfast_syscall+0xfb/frame 0xfffffe2021b70ab0 --- syscall (6, FreeBSD ELF64, sys_close), rip = 0x8019dbeaa, rsp = 0x7fffffffe6a8, rbp = 0x7fffffffe6c0 --- Tracing command nginx pid 1060 tid 101749 td 0xfffff80126a53a00 sched_switch() at 0xffffffff804c956d = sched_switch+0x6ad/frame 0xfffffe2021b7a240 mi_switch() at 0xffffffff804a8d92 = mi_switch+0xd2/frame 0xfffffe2021b7a270 turnstile_wait() at 0xffffffff804ef177 = turnstile_wait+0x2a7/frame 0xfffffe2021b7a2b0 __rw_wlock_hard() at 0xffffffff8049c314 = __rw_wlock_hard+0x94/frame 0xfffffe2021b7a340 in_lltable_lookup() at 0xffffffff80594823 = in_lltable_lookup+0x83/frame 0xfffffe2021b7a360 arpresolve() at 0xffffffff8058d2aa = arpresolve+0x9a/frame 0xfffffe2021b7a3c0 ether_output() at 0xffffffff805755e2 = ether_output+0x2f2/frame 0xfffffe2021b7a460 ip_output() at 0xffffffff805a4200 = ip_output+0x1390/frame 0xfffffe2021b7a5c0 tcp_output() at 0xffffffff806149d5 = tcp_output+0x17a5/frame 0xfffffe2021b7a760 tcp_usr_send() at 0xffffffff8062078b = tcp_usr_send+0x33b/frame 0xfffffe2021b7a7e0 sosend_generic() at 0xffffffff8051cf36 = sosend_generic+0x436/frame 0xfffffe2021b7a8a0 soo_write() at 0xffffffff804fd872 = soo_write+0x42/frame 0xfffffe2021b7a8d0 dofilewrite() at 0xffffffff804f5c97 = dofilewrite+0x87/frame 0xfffffe2021b7a920 kern_writev() at 0xffffffff804f5978 = kern_writev+0x68/frame 0xfffffe2021b7a970 sys_writev() at 0xffffffff804f5be6 = sys_writev+0x36/frame 0xfffffe2021b7a9a0 amd64_syscall() at 0xffffffff806e4051 = amd64_syscall+0x2c1/frame 0xfffffe2021b7aab0 Xfast_syscall() at 0xffffffff806cb2bb = Xfast_syscall+0xfb/frame 0xfffffe2021b7aab0 --- syscall (121, FreeBSD ELF64, sys_writev), rip = 0x8019cc6ba, rsp = 0x7fffffffd268, rbp = 0x7fffffffd2a0 --- Tracing command nginx pid 1059 tid 101817 td 0xfffff8014de1da00 sched_switch() at 0xffffffff804c956d = sched_switch+0x6ad/frame 0xfffffe20220cc240 mi_switch() at 0xffffffff804a8d92 = mi_switch+0xd2/frame 0xfffffe20220cc270 turnstile_wait() at 0xffffffff804ef177 = turnstile_wait+0x2a7/frame 0xfffffe20220cc2b0 __rw_wlock_hard() at 0xffffffff8049c314 = __rw_wlock_hard+0x94/frame 0xfffffe20220cc340 in_lltable_lookup() at 0xffffffff80594823 = in_lltable_lookup+0x83/frame 0xfffffe20220cc360 arpresolve() at 0xffffffff8058d2aa = arpresolve+0x9a/frame 0xfffffe20220cc3c0 ether_output() at 0xffffffff805755e2 = ether_output+0x2f2/frame 0xfffffe20220cc460 ip_output() at 0xffffffff805a4200 = ip_output+0x1390/frame 0xfffffe20220cc5c0 tcp_output() at 0xffffffff806149d5 = tcp_output+0x17a5/frame 0xfffffe20220cc760 tcp_usr_send() at 0xffffffff8062078b = tcp_usr_send+0x33b/frame 0xfffffe20220cc7e0 sosend_generic() at 0xffffffff8051cf36 = sosend_generic+0x436/frame 0xfffffe20220cc8a0 soo_write() at 0xffffffff804fd872 = soo_write+0x42/frame 0xfffffe20220cc8d0 dofilewrite() at 0xffffffff804f5c97 = dofilewrite+0x87/frame 0xfffffe20220cc920 kern_writev() at 0xffffffff804f5978 = kern_writev+0x68/frame 0xfffffe20220cc970 sys_writev() at 0xffffffff804f5be6 = sys_writev+0x36/frame 0xfffffe20220cc9a0 amd64_syscall() at 0xffffffff806e4051 = amd64_syscall+0x2c1/frame 0xfffffe20220ccab0 Xfast_syscall() at 0xffffffff806cb2bb = Xfast_syscall+0xfb/frame 0xfffffe20220ccab0 --- syscall (121, FreeBSD ELF64, sys_writev), rip = 0x8019cc6ba, rsp = 0x7fffffffcea8, rbp = 0x7fffffffcee0 --- Tracing command nginx pid 1058 tid 101816 td 0xfffff8014ddb2500 sched_switch() at 0xffffffff804c956d = sched_switch+0x6ad/frame 0xfffffe20220c7330 mi_switch() at 0xffffffff804a8d92 = mi_switch+0xd2/frame 0xfffffe20220c7360 turnstile_wait() at 0xffffffff804ef177 = turnstile_wait+0x2a7/frame 0xfffffe20220c73a0 __rw_wlock_hard() at 0xffffffff8049c314 = __rw_wlock_hard+0x94/frame 0xfffffe20220c7430 in_lltable_lookup() at 0xffffffff80594823 = in_lltable_lookup+0x83/frame 0xfffffe20220c7450 arpresolve() at 0xffffffff8058d2aa = arpresolve+0x9a/frame 0xfffffe20220c74b0 ether_output() at 0xffffffff805755e2 = ether_output+0x2f2/frame 0xfffffe20220c7550 ip_output() at 0xffffffff805a4200 = ip_output+0x1390/frame 0xfffffe20220c76b0 tcp_output() at 0xffffffff806149d5 = tcp_output+0x17a5/frame 0xfffffe20220c7850 tcp_usr_disconnect() at 0xffffffff80620094 = tcp_usr_disconnect+0x74/frame 0xfffffe20220c7880 soclose() at 0xffffffff8051c238 = soclose+0x38/frame 0xfffffe20220c78b0 _fdrop() at 0xffffffff8045639a = _fdrop+0x1a/frame 0xfffffe20220c78d0 closef() at 0xffffffff80458a53 = closef+0x1e3/frame 0xfffffe20220c7960 closefp() at 0xffffffff804567ad = closefp+0x7d/frame 0xfffffe20220c79a0 amd64_syscall() at 0xffffffff806e4051 = amd64_syscall+0x2c1/frame 0xfffffe20220c7ab0 Xfast_syscall() at 0xffffffff806cb2bb = Xfast_syscall+0xfb/frame 0xfffffe20220c7ab0 --- syscall (6, FreeBSD ELF64, sys_close), rip = 0x8019dbeaa, rsp = 0x7fffffffe6a8, rbp = 0x7fffffffe6c0 --- Tracing command nginx pid 1057 tid 101815 td 0xfffff8014dde1500 sched_switch() at 0xffffffff804c956d = sched_switch+0x6ad/frame 0xfffffe20220c2240 mi_switch() at 0xffffffff804a8d92 = mi_switch+0xd2/frame 0xfffffe20220c2270 turnstile_wait() at 0xffffffff804ef177 = turnstile_wait+0x2a7/frame 0xfffffe20220c22b0 __rw_wlock_hard() at 0xffffffff8049c314 = __rw_wlock_hard+0x94/frame 0xfffffe20220c2340 in_lltable_lookup() at 0xffffffff80594823 = in_lltable_lookup+0x83/frame 0xfffffe20220c2360 arpresolve() at 0xffffffff8058d2aa = arpresolve+0x9a/frame 0xfffffe20220c23c0 ether_output() at 0xffffffff805755e2 = ether_output+0x2f2/frame 0xfffffe20220c2460 ip_output() at 0xffffffff805a4200 = ip_output+0x1390/frame 0xfffffe20220c25c0 tcp_output() at 0xffffffff806149d5 = tcp_output+0x17a5/frame 0xfffffe20220c2760 tcp_usr_send() at 0xffffffff8062078b = tcp_usr_send+0x33b/frame 0xfffffe20220c27e0 sosend_generic() at 0xffffffff8051cf36 = sosend_generic+0x436/frame 0xfffffe20220c28a0 soo_write() at 0xffffffff804fd872 = soo_write+0x42/frame 0xfffffe20220c28d0 dofilewrite() at 0xffffffff804f5c97 = dofilewrite+0x87/frame 0xfffffe20220c2920 kern_writev() at 0xffffffff804f5978 = kern_writev+0x68/frame 0xfffffe20220c2970 sys_writev() at 0xffffffff804f5be6 = sys_writev+0x36/frame 0xfffffe20220c29a0 amd64_syscall() at 0xffffffff806e4051 = amd64_syscall+0x2c1/frame 0xfffffe20220c2ab0 Xfast_syscall() at 0xffffffff806cb2bb = Xfast_syscall+0xfb/frame 0xfffffe20220c2ab0 --- syscall (121, FreeBSD ELF64, sys_writev), rip = 0x8019cc6ba, rsp = 0x7fffffffcc98, rbp = 0x7fffffffccd0 --- Tracing command nginx pid 1055 tid 101800 td 0xfffff8014ddfda00 sched_switch() at 0xffffffff804c956d = sched_switch+0x6ad/frame 0xfffffe2022077240 mi_switch() at 0xffffffff804a8d92 = mi_switch+0xd2/frame 0xfffffe2022077270 turnstile_wait() at 0xffffffff804ef177 = turnstile_wait+0x2a7/frame 0xfffffe20220772b0 __rw_wlock_hard() at 0xffffffff8049c314 = __rw_wlock_hard+0x94/frame 0xfffffe2022077340 in_lltable_lookup() at 0xffffffff80594823 = in_lltable_lookup+0x83/frame 0xfffffe2022077360 arpresolve() at 0xffffffff8058d2aa = arpresolve+0x9a/frame 0xfffffe20220773c0 ether_output() at 0xffffffff805755e2 = ether_output+0x2f2/frame 0xfffffe2022077460 ip_output() at 0xffffffff805a4200 = ip_output+0x1390/frame 0xfffffe20220775c0 tcp_output() at 0xffffffff806149d5 = tcp_output+0x17a5/frame 0xfffffe2022077760 tcp_usr_send() at 0xffffffff8062078b = tcp_usr_send+0x33b/frame 0xfffffe20220777e0 sosend_generic() at 0xffffffff8051cf36 = sosend_generic+0x436/frame 0xfffffe20220778a0 soo_write() at 0xffffffff804fd872 = soo_write+0x42/frame 0xfffffe20220778d0 dofilewrite() at 0xffffffff804f5c97 = dofilewrite+0x87/frame 0xfffffe2022077920 kern_writev() at 0xffffffff804f5978 = kern_writev+0x68/frame 0xfffffe2022077970 sys_writev() at 0xffffffff804f5be6 = sys_writev+0x36/frame 0xfffffe20220779a0 amd64_syscall() at 0xffffffff806e4051 = amd64_syscall+0x2c1/frame 0xfffffe2022077ab0 Xfast_syscall() at 0xffffffff806cb2bb = Xfast_syscall+0xfb/frame 0xfffffe2022077ab0 --- syscall (121, FreeBSD ELF64, sys_writev), rip = 0x8019cc6ba, rsp = 0x7fffffffcc58, rbp = 0x7fffffffcc90 --- Tracing command intr pid 12 tid 100015 td 0xfffff8011422b000 sched_switch() at 0xffffffff804c956d = sched_switch+0x6ad/frame 0xfffffe1f9e1cf7a0 mi_switch() at 0xffffffff804a8d92 = mi_switch+0xd2/frame 0xfffffe1f9e1cf7d0 turnstile_wait() at 0xffffffff804ef177 = turnstile_wait+0x2a7/frame 0xfffffe1f9e1cf810 __rw_wlock_hard() at 0xffffffff8049c314 = __rw_wlock_hard+0x94/frame 0xfffffe1f9e1cf8a0 in_losing() at 0xffffffff8059c8e8 = in_losing+0x98/frame 0xfffffe1f9e1cf8c0 tcp_timer_rexmt() at 0xffffffff8061e768 = tcp_timer_rexmt+0x428/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 0xfffffe1f9e1d47a0 mi_switch() at 0xffffffff804a8d92 = mi_switch+0xd2/frame 0xfffffe1f9e1d47d0 turnstile_wait() at 0xffffffff804ef177 = turnstile_wait+0x2a7/frame 0xfffffe1f9e1d4810 __rw_wlock_hard() at 0xffffffff8049c314 = __rw_wlock_hard+0x94/frame 0xfffffe1f9e1d48a0 in_losing() at 0xffffffff8059c8e8 = in_losing+0x98/frame 0xfffffe1f9e1d48c0 tcp_timer_rexmt() at 0xffffffff8061e768 = tcp_timer_rexmt+0x428/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 0xfffffe1f9e1d9700 mi_switch() at 0xffffffff804a8d92 = mi_switch+0xd2/frame 0xfffffe1f9e1d9730 turnstile_wait() at 0xffffffff804ef177 = turnstile_wait+0x2a7/frame 0xfffffe1f9e1d9770 __rw_wlock_hard() at 0xffffffff8049c314 = __rw_wlock_hard+0x94/frame 0xfffffe1f9e1d9800 in_pcbfree() at 0xffffffff8059be10 = in_pcbfree+0x290/frame 0xfffffe1f9e1d9840 tcp_usr_detach() at 0xffffffff8061fff8 = tcp_usr_detach+0x78/frame 0xfffffe1f9e1d9860 sofree() at 0xffffffff8051c0a9 = sofree+0x109/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 0xfffffe1f9e1de7c0 mi_switch() at 0xffffffff804a8d92 = mi_switch+0xd2/frame 0xfffffe1f9e1de7f0 turnstile_wait() at 0xffffffff804ef177 = turnstile_wait+0x2a7/frame 0xfffffe1f9e1de830 __rw_wlock_hard() at 0xffffffff8049c314 = __rw_wlock_hard+0x94/frame 0xfffffe1f9e1de8c0 tcp_timer_delack() at 0xffffffff8061db1c = tcp_timer_delack+0x2c/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 0xfffffe1f9e1e37a0 mi_switch() at 0xffffffff804a8d92 = mi_switch+0xd2/frame 0xfffffe1f9e1e37d0 turnstile_wait() at 0xffffffff804ef177 = turnstile_wait+0x2a7/frame 0xfffffe1f9e1e3810 __rw_wlock_hard() at 0xffffffff8049c314 = __rw_wlock_hard+0x94/frame 0xfffffe1f9e1e38a0 in_losing() at 0xffffffff8059c8e8 = in_losing+0x98/frame 0xfffffe1f9e1e38c0 tcp_timer_rexmt() at 0xffffffff8061e768 = tcp_timer_rexmt+0x428/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_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 0xfffffe1f9e1e87a0 mi_switch() at 0xffffffff804a8d92 = mi_switch+0xd2/frame 0xfffffe1f9e1e87d0 turnstile_wait() at 0xffffffff804ef177 = turnstile_wait+0x2a7/frame 0xfffffe1f9e1e8810 __rw_wlock_hard() at 0xffffffff8049c314 = __rw_wlock_hard+0x94/frame 0xfffffe1f9e1e88a0 in_losing() at 0xffffffff8059c8e8 = in_losing+0x98/frame 0xfffffe1f9e1e88c0 tcp_timer_rexmt() at 0xffffffff8061e768 = tcp_timer_rexmt+0x428/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 0xfffffe1f9e1ed3a0 mi_switch() at 0xffffffff804a8d92 = mi_switch+0xd2/frame 0xfffffe1f9e1ed3d0 turnstile_wait() at 0xffffffff804ef177 = turnstile_wait+0x2a7/frame 0xfffffe1f9e1ed410 __rw_wlock_hard() at 0xffffffff8049c314 = __rw_wlock_hard+0x94/frame 0xfffffe1f9e1ed4a0 in_lltable_lookup() at 0xffffffff80594823 = in_lltable_lookup+0x83/frame 0xfffffe1f9e1ed4c0 arpresolve() at 0xffffffff8058d2aa = arpresolve+0x9a/frame 0xfffffe1f9e1ed520 ether_output() at 0xffffffff805755e2 = ether_output+0x2f2/frame 0xfffffe1f9e1ed5c0 ip_output() at 0xffffffff805a4200 = ip_output+0x1390/frame 0xfffffe1f9e1ed720 tcp_output() at 0xffffffff806149d5 = tcp_output+0x17a5/frame 0xfffffe1f9e1ed8c0 tcp_timer_delack() at 0xffffffff8061db8f = tcp_timer_delack+0x9f/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 0xfffffe1f9e1f2700 mi_switch() at 0xffffffff804a8d92 = mi_switch+0xd2/frame 0xfffffe1f9e1f2730 turnstile_wait() at 0xffffffff804ef177 = turnstile_wait+0x2a7/frame 0xfffffe1f9e1f2770 __rw_wlock_hard() at 0xffffffff8049c314 = __rw_wlock_hard+0x94/frame 0xfffffe1f9e1f2800 in_pcbfree() at 0xffffffff8059be10 = in_pcbfree+0x290/frame 0xfffffe1f9e1f2840 tcp_usr_detach() at 0xffffffff8061fff8 = tcp_usr_detach+0x78/frame 0xfffffe1f9e1f2860 sofree() at 0xffffffff8051c0a9 = sofree+0x109/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 0xfffffe1f9e1f7360 mi_switch() at 0xffffffff804a8d92 = mi_switch+0xd2/frame 0xfffffe1f9e1f7390 critical_exit() at 0xffffffff804a6bee = critical_exit+0x7e/frame 0xfffffe1f9e1f73b0 ipi_bitmap_handler() at 0xffffffff80775629 = ipi_bitmap_handler+0x79/frame 0xfffffe1f9e1f73f0 Xipi_intr_bitmap_handler() at 0xffffffff806cc15e = Xipi_intr_bitmap_handler+0x8e/frame 0xfffffe1f9e1f73f0 --- interrupt, rip = 0xffffffff806e16c4, rsp = 0xfffffe1f9e1f74c0, rbp = 0xfffffe1f9e1f74c0 --- bcopy() at 0xffffffff806e16c4 = bcopy+0x24/frame 0xfffffe1f9e1f74c0 arpresolve() at 0xffffffff8058d381 = arpresolve+0x171/frame 0xfffffe1f9e1f7520 ether_output() at 0xffffffff805755e2 = ether_output+0x2f2/frame 0xfffffe1f9e1f75c0 ip_output() at 0xffffffff805a4200 = ip_output+0x1390/frame 0xfffffe1f9e1f7720 tcp_output() at 0xffffffff806149d5 = tcp_output+0x17a5/frame 0xfffffe1f9e1f78c0 tcp_timer_rexmt() at 0xffffffff8061e7de = tcp_timer_rexmt+0x49e/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 0xfffffe1f9e1fc3a0 mi_switch() at 0xffffffff804a8d92 = mi_switch+0xd2/frame 0xfffffe1f9e1fc3d0 turnstile_wait() at 0xffffffff804ef177 = turnstile_wait+0x2a7/frame 0xfffffe1f9e1fc410 __rw_wlock_hard() at 0xffffffff8049c314 = __rw_wlock_hard+0x94/frame 0xfffffe1f9e1fc4a0 in_lltable_lookup() at 0xffffffff80594823 = in_lltable_lookup+0x83/frame 0xfffffe1f9e1fc4c0 arpresolve() at 0xffffffff8058d2aa = arpresolve+0x9a/frame 0xfffffe1f9e1fc520 ether_output() at 0xffffffff805755e2 = ether_output+0x2f2/frame 0xfffffe1f9e1fc5c0 ip_output() at 0xffffffff805a4200 = ip_output+0x1390/frame 0xfffffe1f9e1fc720 tcp_output() at 0xffffffff806149d5 = tcp_output+0x17a5/frame 0xfffffe1f9e1fc8c0 tcp_timer_delack() at 0xffffffff8061db8f = tcp_timer_delack+0x9f/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 0xfffffe0000382700 mi_switch() at 0xffffffff804a8d92 = mi_switch+0xd2/frame 0xfffffe0000382730 turnstile_wait() at 0xffffffff804ef177 = turnstile_wait+0x2a7/frame 0xfffffe0000382770 __rw_wlock_hard() at 0xffffffff8049c314 = __rw_wlock_hard+0x94/frame 0xfffffe0000382800 in_pcbfree() at 0xffffffff8059be10 = in_pcbfree+0x290/frame 0xfffffe0000382840 tcp_usr_detach() at 0xffffffff8061fff8 = tcp_usr_detach+0x78/frame 0xfffffe0000382860 sofree() at 0xffffffff8051c0a9 = sofree+0x109/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 0xfffffe0000387700 mi_switch() at 0xffffffff804a8d92 = mi_switch+0xd2/frame 0xfffffe0000387730 turnstile_wait() at 0xffffffff804ef177 = turnstile_wait+0x2a7/frame 0xfffffe0000387770 __rw_wlock_hard() at 0xffffffff8049c314 = __rw_wlock_hard+0x94/frame 0xfffffe0000387800 in_pcbfree() at 0xffffffff8059be10 = in_pcbfree+0x290/frame 0xfffffe0000387840 tcp_usr_detach() at 0xffffffff8061fff8 = tcp_usr_detach+0x78/frame 0xfffffe0000387860 sofree() at 0xffffffff8051c0a9 = sofree+0x109/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 --- Tracing command intr pid 12 tid 100103 td 0xfffff8012508ea00 sched_switch() at 0xffffffff804c956d = sched_switch+0x6ad/frame 0xfffffe2020ea82d0 mi_switch() at 0xffffffff804a8d92 = mi_switch+0xd2/frame 0xfffffe2020ea8300 turnstile_wait() at 0xffffffff804ef177 = turnstile_wait+0x2a7/frame 0xfffffe2020ea8340 __rw_wlock_hard() at 0xffffffff8049c314 = __rw_wlock_hard+0x94/frame 0xfffffe2020ea83d0 in_pcbfree() at 0xffffffff8059be10 = in_pcbfree+0x290/frame 0xfffffe2020ea8410 tcp_usr_detach() at 0xffffffff8061fff8 = tcp_usr_detach+0x78/frame 0xfffffe2020ea8430 sofree() at 0xffffffff8051c0a9 = sofree+0x109/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 0xfffffe2020eb2290 mi_switch() at 0xffffffff804a8d92 = mi_switch+0xd2/frame 0xfffffe2020eb22c0 turnstile_wait() at 0xffffffff804ef177 = turnstile_wait+0x2a7/frame 0xfffffe2020eb2300 __rw_wlock_hard() at 0xffffffff8049c314 = __rw_wlock_hard+0x94/frame 0xfffffe2020eb2390 in_pcbfree() at 0xffffffff8059be10 = in_pcbfree+0x290/frame 0xfffffe2020eb23d0 tcp_usr_detach() at 0xffffffff8061fff8 = tcp_usr_detach+0x78/frame 0xfffffe2020eb23f0 sofree() at 0xffffffff8051c0a9 = sofree+0x109/frame 0xfffffe2020eb2420 tcp_close() at 0xffffffff80618150 = tcp_close+0xd0/frame 0xfffffe2020eb2450 tcp_twstart() at 0xffffffff8061f0e7 = tcp_twstart+0x2b7/frame 0xfffffe2020eb2490 tcp_do_segment() at 0xffffffff80610bdf = tcp_do_segment+0x201f/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 cpustop_handler() at 0xffffffff80775998 = cpustop_handler+0x28/frame 0xfffffe1f9e16dcf0 ipi_nmi_handler() at 0xffffffff8077595a = ipi_nmi_handler+0x4a/frame 0xfffffe1f9e16dd10 trap() at 0xffffffff806e2e4a = trap+0x3a/frame 0xfffffe1f9e16df20 nmi_calltrap() at 0xffffffff806cb413 = nmi_calltrap+0x8/frame 0xfffffe1f9e16df20 --- trap 0x13, rip = 0xffffffff8049c71d, rsp = 0xfffffe2020ebc410, rbp = 0xfffffe2020ebc420 --- __rw_try_wlock() at 0xffffffff8049c71d = __rw_try_wlock+0x4d/frame 0xfffffe2020ebc420 tcp_tw_2msl_scan() at 0xffffffff8061f1f6 = tcp_tw_2msl_scan+0xc6/frame 0xfffffe2020ebc450 /usr/src/sys/netinet/tcp_timewait.c:707 tcp_twstart() at 0xffffffff8061eed3 = tcp_twstart+0xa3/frame 0xfffffe2020ebc490 tcp_do_segment() at 0xffffffff80610bdf = tcp_do_segment+0x201f/frame 0xfffffe2020ebc590 tcp_input() at 0xffffffff8060e17c = tcp_input+0xe1c/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 0xfffffe2020f302d0 mi_switch() at 0xffffffff804a8d92 = mi_switch+0xd2/frame 0xfffffe2020f30300 turnstile_wait() at 0xffffffff804ef177 = turnstile_wait+0x2a7/frame 0xfffffe2020f30340 __rw_wlock_hard() at 0xffffffff8049c314 = __rw_wlock_hard+0x94/frame 0xfffffe2020f303d0 in_pcbfree() at 0xffffffff8059be10 = in_pcbfree+0x290/frame 0xfffffe2020f30410 tcp_usr_detach() at 0xffffffff8061fff8 = tcp_usr_detach+0x78/frame 0xfffffe2020f30430 sofree() at 0xffffffff8051c0a9 = sofree+0x109/frame 0xfffffe2020f30460 tcp_close() at 0xffffffff80618150 = tcp_close+0xd0/frame 0xfffffe2020f30490 tcp_do_segment() at 0xffffffff8060f6cb = tcp_do_segment+0xb0b/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 --- current version of /usr/src/sys/netinet/tcp_timewait.c 700 inp = tw->tw_inpcb; 701 in_pcbref(inp); 702 TW_RUNLOCK(V_tw_lock); 703 704 //retry: 705 if (INP_INFO_TRY_RLOCK(&V_tcbinfo)) { 706 707 if (INP_TRY_WLOCK(inp)) { 708 tw = intotw(inp); 709 if (in_pcbrele_wlocked(inp)) { 710 KASSERT(tw == NULL, ("%s: held last inp " 711 "reference but tw not NULL", __func__)); 712 INP_INFO_RUNLOCK(&V_tcbinfo); 713 continue; 714 } 715 716 if (tw == NULL) { 717 /* tcp_twclose() has already been called */ 718 INP_WUNLOCK(inp); 719 INP_INFO_RUNLOCK(&V_tcbinfo); 720 continue; 721 } 722 723 tcp_twclose(tw, reuse); 724 INP_INFO_RUNLOCK(&V_tcbinfo); 725 if (reuse) 726 return tw; 727 } else { 728 INP_INFO_RUNLOCK(&V_tcbinfo); 729 goto retry; 730 } 731 } else { 732 /* INP_INFO lock is busy, continue later. */ 733 if (INP_TRY_WLOCK(inp)) { 734 if (!in_pcbrele_wlocked(inp)) 735 INP_WUNLOCK(inp); 736 break; 737 } else { 738 goto retry; 739 } 740 } 741 } 742 retry: 743 return NULL; 744 }
On Wed, 28 Sep 2016 12:06:47 +0200 Julien Charbon <julien.charbon at gmail.com> wrote:> > I am still trying to reproduce your issue, without success so far.All: please remember to trim your quotes. Thank you. Carry on. -- Regards, Torfinn Ingolfsen <torfinn.ingolfsen at getmail.no>
Hi, On 9/28/16 1:59 PM, Slawa Olhovchenkov wrote:> On Wed, Sep 28, 2016 at 12:06:47PM +0200, Julien Charbon wrote: >> <SNIP> >> I am still trying to reproduce your issue, without success so far.Thanks for Slawa effort and multiple debug report we start seeing the bottom of this issue and it seems to be a generic one. The most useful report being: panic: tcp_detach: INP_TIMEWAIT && INP_DROPPED && tp != NULL cpuid = 4 KDB: stack backtrace: db_trace_self_wrapper() at 0xffffffff8032467b db_trace_self_wrapper+0x2b/frame 0xfffffe1f9e1f8730 vpanic() at 0xffffffff804b5672 = vpanic+0x182/frame 0xfffffe1f9e1f87b0 kassert_panic() at 0xffffffff804b54e6 = kassert_panic+0x126/frame 0xfffffe1f9e1f8820 tcp_usr_detach() at 0xffffffff806564dc = tcp_usr_detach+0x1bc/frame 0xfffffe1f9e1f8850 sofree() at 0xffffffff8053de66 = sofree+0x1a6/frame 0xfffffe1f9e1f8880 tcp_close() at 0xffffffff8064dd8e = tcp_close+0x11e/frame 0xfffffe1f9e1f88b0 tcp_timer_2msl() at 0xffffffff80653c28 = tcp_timer_2msl+0x278/frame 0xfffffe1f9e1f88e0 softclock_call_cc() at 0xffffffff804cbacc softclock_call_cc+0x19c/frame 0xfffffe1f9e1f89c0 softclock() at 0xffffffff804cbec7 = softclock+0x47/frame 0xfffffe1f9e1f89e0 intr_event_execute_handlers() at 0xffffffff8047aa86 intr_event_execute_handlers+0x96/frame 0xfffffe1f9e1f8a20 ithread_loop() at 0xffffffff8047b106 = ithread_loop+0xa6/frame 0xfffffe1f9e1f8a70 fork_exit() at 0xffffffff804781b4 = fork_exit+0x84/frame 0xfffffe1f9e1f8ab0 fork_trampoline() at 0xffffffff80713fce = fork_trampoline+0xe/frame 0xfffffe1f9e1f8ab0 The scenario: 1. thread1: tcp_timer_2msl() expires and tcp_close() is called to clean this TCP connection. 2. thread1: In tcp_close() the inp is marked with INP_DROPPED flag, the process continues and calls INP_WUNLOCK() here: https://github.com/freebsd/freebsd/blob/releng/11.0/sys/netinet/tcp_subr.c#L1568 3. thread2: Now because INP_WLOCK is released, the inp can transition to INP_TIMEWAIT state and nothing is preventing it. 4. thread2: During the INP_TIMEWAIT state transition, the inp is marked with INP_TIMEWAIT flag. 5. thread1: Back in business and tcp_close() call continues with sofree() -> tcp_usr_detach() -> tcp_detach(). Then as inp is marked with INP_DROPPED|INP_TIMEWAIT flags, in_pcbfree() is called. w/ INVARIANTS you have an assertion here, w/o INVARIANTS process continues. 6. Later: tcp_twclose() cleans up this INP_TIMEWAIT inp and calls in_pcbfree() again to achieve a fancy inp double-free. This issue is a tricky one and seems here since quite a while. It has been witness at least once in 10.1 and by two different people in 11.0. Astute questions: o Why INP_DROPPED flag is not tested in tcp_input() in the first place? When you are marked as INP_DROPPED, you are almost dead, you should not be allowed to transition to a different state! Good point, and tcp_input() relies on the fact that INP_DROPPED inps are no more in TCP hash table. But tcp_input() in some cases do relock INP (see relocked: label) and if it does check a lot of things after having relocked the inp it does not check for a recently added INP_DROPPED flag. o Why tcp_detach() does an unconditional in_pcbfree() for inps in TIMEWAIT state? This because inps in TIMEWAIT state have only one exit: Being freed. And it is the duty of tcp_detach() to free all inps with INP_DROPPED|INP_TIMEWAIT. o Why this issue is so rare? Good question, I can see how to have a specific TCP traffic to make it more frequent but no definitive answer yet. Fix proposal: This issue description is still a bit fresh but I would enforce that an inp with INP_DROPPED flag should not be allowed to change state. Thing learned: When re-locking an inp, it might have changed a lot, and you might not like what it became. Thanks again to Slawa, for his numerous debug reports and always questioning my explanations. His last question directly led to this finding. He is testing a quick workaround patch to check if there is more. I will create a review with a fix proposal, and don't hesitate if you have other comments on this issue. -- Julien -------------- next part -------------- A non-text attachment was scrubbed... Name: signature.asc Type: application/pgp-signature Size: 496 bytes Desc: OpenPGP digital signature URL: <http://lists.freebsd.org/pipermail/freebsd-stable/attachments/20161006/742521da/attachment.sig>