From owner-freebsd-stable@FreeBSD.ORG Tue Nov 13 18:31:17 2012 Return-Path: Delivered-To: freebsd-stable@freebsd.org Received: from mx1.freebsd.org (mx1.freebsd.org [69.147.83.52]) by hub.freebsd.org (Postfix) with ESMTP id 00E2687A for ; Tue, 13 Nov 2012 18:31:16 +0000 (UTC) (envelope-from markus.gebert@hostpoint.ch) Received: from mail.adm.hostpoint.ch (mail.adm.hostpoint.ch [IPv6:2a00:d70:0:a::e0]) by mx1.freebsd.org (Postfix) with ESMTP id A1C598FC0C for ; Tue, 13 Nov 2012 18:31:14 +0000 (UTC) Received: from [2001:1620:2013:1:e8ec:d52:8672:17b] (port=65228) by mail.adm.hostpoint.ch with esmtpsa (TLSv1:AES128-SHA:128) (Exim 4.69 (FreeBSD)) (envelope-from ) id 1TYLG5-000Jwk-8d for freebsd-stable@freebsd.org; Tue, 13 Nov 2012 19:30:49 +0100 From: Markus Gebert Content-Type: text/plain; charset=us-ascii Content-Transfer-Encoding: quoted-printable Subject: thread taskq / unp_gc() using 100% cpu and stalling unix socket IPC Message-Id: <6908B498-6978-4995-B081-8D504ECB5C0A@hostpoint.ch> Date: Tue, 13 Nov 2012 19:30:34 +0100 To: freebsd-stable Mime-Version: 1.0 (Mac OS X Mail 6.2 \(1499\)) X-Mailer: Apple Mail (2.1499) X-BeenThere: freebsd-stable@freebsd.org X-Mailman-Version: 2.1.14 Precedence: list List-Id: Production branch of FreeBSD source code List-Unsubscribe: , List-Archive: List-Post: List-Help: List-Subscribe: , X-List-Received-Date: Tue, 13 Nov 2012 18:31:17 -0000 Hi there We have a pair of servers running FreeBSD 9.1-RC3 that act as = transparent layer 7 loadbalancer (relayd) and pop/imap proxy (dovecot). = Only one of them is active at a given time, it's a failover setup. =46rom = time to time the active one gets in a state in which the 'thread taskq' = thread uses up 100% of one cpu on its own, like here: ---- PID USERNAME PRI NICE SIZE RES STATE C TIME WCPU = COMMAND 0 root 8 0 0K 3968K CPU12 12 9:49 100.00% = kernel{thread taskq} ---- Most of the userland processes get stalled and if the sitation is not = resolved, their network services stop responding alltogether after some = time. This affects relayd and dovecot for sure, but not sshd. When processes are slow, they often block in states like '*unp_l' or = 'pipewr' according to top, and overall cpu time spent in kernel grows by = factors (and system load too). See [0], [1], [2] for top screenshots = when things work badly. Under normal circumstances load is below 5 and = systime below 5%. Load during daytime makes this situation more likely = to occur. At the same time it does _not_ seem to be triggered by any = sudden load peaks (e.g. more network connections etc.), so I guess it's = some kind of race condition. Today I had the chance to get a few ddb traces of the 'thread taskq' = while the problem was occuring. Every few seconds I ran a ddb script and = continued. I got five samples, after that ddb became unresponsive. All = of them show the thread executing in unp_gc() like here: ---- unp_gc() at unp_gc+0x81 taskqueue_run_locked() at taskqueue_run_locked+0x85 taskqueue_thread_loop() at taskqueue_thread_loop+0x46 fork_exit() at fork_exit+0x11f fork_trampoline() at fork_trampoline+0xe ---- See all samples under [3]. This is consistent with some textdumps and ddb sessions I've done. Also, = the sysctl 'net.local.taskcount' seems to increase at much higher rates = when the problem occurs. To me it looks like the unix socket GC is triggered way too often and/or = running too long, which uses cpu and worse, causes a lot of contention = around the unp_list_lock which in turn causes delays for all processes = relaying on unix sockets for IPC. I don't know why the unp_gc() is called so often and what's triggering = this. Sometimes this condition only lasts for a few seconds and then resolves = itself before the thread taskq reaches 100% cpu usage. Sometimes it will = last, render dovecot/relayd unresponsive and can only be resolved by = taking load off the system (forcefully restart services). Booting a kernel with INVARIANTS and WITNESS did not bring much more = clues. The system ends up panicing with 'soabort: so_count' after a few = minutes of load, but the trace[4] does not seem related to unix sockets, = so that might be another problem. System info, boot dmesg and some configs can be found under [5]. I hope somebody can help me debug this further. Markus [0] last pid: 10227; load averages: 18.81, 13.02, 8.09 = up 0+18:14:55 13:07:53 136 processes: 4 running, 53 sleeping, 1 waiting, 78 lock CPU 0: 5.9% user, 0.0% nice, 54.5% system, 3.5% interrupt, 36.1% = idle CPU 1: 5.9% user, 0.0% nice, 56.5% system, 3.1% interrupt, 34.5% = idle CPU 2: 4.3% user, 0.0% nice, 58.8% system, 3.9% interrupt, 32.9% = idle CPU 3: 6.3% user, 0.0% nice, 60.4% system, 2.0% interrupt, 31.4% = idle CPU 4: 3.5% user, 0.0% nice, 59.2% system, 2.7% interrupt, 34.5% = idle CPU 5: 3.9% user, 0.0% nice, 60.0% system, 1.6% interrupt, 34.5% = idle CPU 6: 4.3% user, 0.0% nice, 62.0% system, 1.2% interrupt, 32.5% = idle CPU 7: 8.6% user, 0.0% nice, 56.9% system, 0.8% interrupt, 33.7% = idle CPU 8: 5.1% user, 0.0% nice, 59.1% system, 0.0% interrupt, 35.8% = idle CPU 9: 7.1% user, 0.0% nice, 56.3% system, 0.0% interrupt, 36.6% = idle CPU 10: 4.7% user, 0.0% nice, 61.0% system, 0.0% interrupt, 34.3% = idle CPU 11: 5.5% user, 0.0% nice, 60.8% system, 0.0% interrupt, 33.7% = idle CPU 12: 6.3% user, 0.0% nice, 61.8% system, 0.4% interrupt, 31.5% = idle CPU 13: 8.3% user, 0.0% nice, 57.1% system, 0.0% interrupt, 34.6% = idle CPU 14: 9.1% user, 0.0% nice, 58.3% system, 0.0% interrupt, 32.7% = idle CPU 15: 7.9% user, 0.0% nice, 55.9% system, 0.0% interrupt, 36.2% = idle CPU 16: 13.4% user, 0.0% nice, 52.8% system, 0.0% interrupt, 33.9% = idle CPU 17: 9.8% user, 0.0% nice, 55.3% system, 0.0% interrupt, 34.9% = idle CPU 18: 5.9% user, 0.0% nice, 62.0% system, 0.0% interrupt, 32.2% = idle CPU 19: 5.1% user, 0.0% nice, 62.6% system, 0.0% interrupt, 32.3% = idle CPU 20: 5.5% user, 0.0% nice, 60.8% system, 0.0% interrupt, 33.7% = idle CPU 21: 10.6% user, 0.0% nice, 57.1% system, 0.0% interrupt, 32.3% = idle CPU 22: 5.9% user, 0.0% nice, 58.8% system, 0.0% interrupt, 35.3% = idle CPU 23: 6.3% user, 0.0% nice, 59.6% system, 0.0% interrupt, 34.1% = idle Mem: 3551M Active, 1351M Inact, 2905M Wired, 8K Cache, 7488K Buf, 85G = Free ARC: 1073M Total, 107M MRU, 828M MFU, 784K Anon, 7647K Header, 130M = Other Swap: 8192M Total, 8192M Free PID USERNAME THR PRI NICE SIZE RES STATE C TIME WCPU = COMMAND 11 root 24 155 ki31 0K 384K CPU23 23 431.4H 847.95% = idle 0 root 248 -8 0 0K 3968K - 1 10:24 89.45% = kernel 2880 _relayd 1 79 0 69608K 54764K *unp_l 22 18:47 25.68% = relayd 2879 _relayd 1 80 0 49128K 34232K *unp_l 6 9:22 25.29% = relayd 2881 _relayd 1 79 0 73704K 57092K *unp_l 9 2:54 24.76% = relayd 2877 _relayd 1 79 0 2948M 2936M *unp_l 1 24:25 24.27% = relayd 2873 root 1 79 0 22584K 4180K *unp_l 23 1:38 23.68% = relayd 3017 root 1 79 0 19860K 2316K *unp_l 2 2:58 22.66% = log 2878 _relayd 1 79 0 57320K 42428K *unp_l 3 17:27 22.27% = relayd 3010 dovenull 1 31 0 67240K 39408K CPU6 6 4:06 22.27% = imap-login 7607 dovecot 1 78 0 58036K 9580K *unp_l 23 1:02 22.27% = auth 3009 dovenull 1 78 0 67240K 39756K *unp_l 17 3:06 21.88% = imap-login 3004 dovenull 1 78 0 63144K 36512K *unp_l 8 1:42 21.29% = imap-login 2998 dovenull 1 78 0 67240K 39556K *unp_l 13 2:47 21.09% = imap-login 7619 dovenull 1 43 0 50856K 25264K *unp_l 12 0:53 21.09% = imap-login 3006 dovenull 1 78 0 63144K 38464K *unp_l 15 3:14 20.65% = imap-login 83740 dovenull 1 78 0 59048K 30956K *unp_l 12 1:57 20.65% = imap-login 2993 dovenull 1 47 0 63144K 37984K *unp_l 17 1:39 20.65% = imap-login 3007 dovenull 1 78 0 63144K 38736K *unp_l 21 3:19 20.56% = imap-login 2994 dovenull 1 78 0 67240K 40144K *unp_l 11 3:52 20.46% = imap-login 7679 dovenull 1 78 0 50856K 24804K *unp_l 4 0:54 20.46% = imap-login 7690 dovenull 1 78 0 50856K 25444K *unp_l 17 0:50 20.46% = imap-login 3008 dovenull 1 78 0 67240K 39248K *unp_l 15 3:16 20.36% = imap-login 3001 dovenull 1 78 0 59048K 34072K *unp_l 21 1:45 20.26% = imap-login 84187 dovenull 1 78 0 63144K 38116K *unp_l 4 3:19 20.07% = imap-login 3000 dovenull 1 78 0 63144K 38832K *unp_l 6 3:40 19.97% = imap-login 83594 dovenull 1 78 0 54952K 28620K *unp_l 9 1:39 19.97% = imap-login 2992 dovenull 1 78 0 67240K 39876K *unp_l 0 3:27 19.87% = imap-login 3012 dovenull 1 78 0 63144K 39064K *unp_l 22 3:03 19.78% = imap-login 87238 dovenull 1 77 0 63144K 39028K *unp_l 1 2:45 19.78% = imap-login 87057 dovenull 1 77 0 67240K 39388K *unp_l 3 2:58 19.68% = imap-login 86973 dovenull 1 77 0 63144K 38464K *unp_l 2 2:52 19.68% = imap-login 85175 dovenull 1 77 0 63144K 38832K *unp_l 12 2:57 19.58% = imap-login 7618 dovenull 1 78 0 54952K 26424K *unp_l 2 0:53 19.58% = imap-login 2995 dovenull 1 77 0 67240K 40504K *unp_l 16 3:02 19.48% = imap-login 86151 dovenull 1 77 0 63144K 38484K *unp_l 11 2:53 19.48% = imap-login 83822 dovenull 1 78 0 63144K 36436K *unp_l 9 2:21 19.48% = imap-login 86132 dovenull 1 78 0 63144K 37948K *unp_l 7 2:59 19.38% = imap-login 7689 dovenull 1 78 0 50856K 25064K *unp_l 19 0:55 19.38% = imap-login 84186 dovenull 1 77 0 63144K 38252K *unp_l 18 2:54 19.09% = imap-login 2999 dovenull 1 77 0 63144K 37760K *unp_l 13 2:00 19.09% = imap-login 3011 dovenull 1 36 0 63144K 36624K *unp_l 3 1:48 19.09% = imap-login 2996 dovenull 1 45 0 63144K 38972K *unp_l 7 3:24 18.99% = imap-login 83731 dovenull 1 45 0 54952K 28824K *unp_l 8 1:48 18.80% = imap-login 3002 dovenull 1 36 0 50856K 22748K *unp_l 19 0:55 18.65% = imap-login 25589 dovenull 1 40 0 63144K 37164K *unp_l 4 1:42 18.46% = imap-login 3021 dovecot 1 77 0 23952K 8924K *unp_l 10 2:04 18.36% = director 2997 dovenull 1 77 0 63144K 38872K *unp_l 16 3:13 18.26% = imap-login [1] last pid: 15656; load averages: 29.20, 16.70, 10.67 = up 0+18:43:35 13:36:33 525 processes: 44 running, 426 sleeping, 55 waiting CPU 0: 1.9% user, 0.0% nice, 67.4% system, 1.5% interrupt, 29.1% = idle CPU 1: 1.9% user, 0.0% nice, 72.8% system, 0.8% interrupt, 24.5% = idle CPU 2: 0.8% user, 0.0% nice, 70.1% system, 0.8% interrupt, 28.4% = idle CPU 3: 1.5% user, 0.0% nice, 70.1% system, 1.9% interrupt, 26.4% = idle CPU 4: 0.0% user, 0.0% nice, 73.6% system, 0.8% interrupt, 25.7% = idle CPU 5: 1.9% user, 0.0% nice, 69.0% system, 0.8% interrupt, 28.4% = idle CPU 6: 0.8% user, 0.0% nice, 69.7% system, 1.5% interrupt, 28.0% = idle CPU 7: 0.0% user, 0.0% nice, 73.2% system, 3.1% interrupt, 23.8% = idle CPU 8: 2.3% user, 0.0% nice, 77.8% system, 0.0% interrupt, 19.9% = idle CPU 9: 2.3% user, 0.0% nice, 74.3% system, 0.0% interrupt, 23.4% = idle CPU 10: 1.1% user, 0.0% nice, 75.1% system, 0.0% interrupt, 23.8% = idle CPU 11: 1.2% user, 0.0% nice, 65.0% system, 0.0% interrupt, 33.8% = idle CPU 12: 0.0% user, 0.0% nice, 77.0% system, 0.0% interrupt, 23.0% = idle CPU 13: 0.8% user, 0.0% nice, 76.2% system, 0.0% interrupt, 23.0% = idle CPU 14: 1.1% user, 0.0% nice, 75.1% system, 0.0% interrupt, 23.8% = idle CPU 15: 0.8% user, 0.0% nice, 75.9% system, 0.0% interrupt, 23.4% = idle CPU 16: 0.8% user, 0.0% nice, 73.6% system, 0.0% interrupt, 25.7% = idle CPU 17: 2.3% user, 0.0% nice, 74.3% system, 0.0% interrupt, 23.4% = idle CPU 18: 1.1% user, 0.0% nice, 70.5% system, 0.0% interrupt, 28.4% = idle CPU 19: 0.8% user, 0.0% nice, 73.6% system, 0.0% interrupt, 25.7% = idle CPU 20: 3.4% user, 0.0% nice, 75.9% system, 0.0% interrupt, 20.7% = idle CPU 21: 1.9% user, 0.0% nice, 76.6% system, 0.0% interrupt, 21.5% = idle CPU 22: 1.9% user, 0.0% nice, 75.5% system, 0.0% interrupt, 22.6% = idle CPU 23: 1.1% user, 0.0% nice, 75.5% system, 0.0% interrupt, 23.4% = idle Mem: 688M Active, 1431M Inact, 3064M Wired, 8K Cache, 7488K Buf, 88G = Free ARC: 1212M Total, 107M MRU, 965M MFU, 1040K Anon, 8010K Header, 131M = Other Swap: 8192M Total, 8192M Free PID USERNAME PRI NICE SIZE RES STATE C TIME WCPU = COMMAND 0 root 8 0 0K 3968K CPU12 12 9:49 100.00% = kernel{thread taskq} 2873 root 84 0 22584K 4180K CPU1 1 2:53 44.58% = relayd 2879 _relayd 84 0 49128K 34268K CPU9 1 12:17 43.26% = relayd 2877 _relayd 52 0 69608K 54400K kqread 22 30:07 39.45% = relayd 2880 _relayd 84 0 65512K 50692K CPU21 21 23:22 39.36% = relayd 2878 _relayd 52 0 57320K 42432K kqread 14 21:54 39.16% = relayd 2881 _relayd 83 0 49128K 31572K CPU4 4 4:34 38.67% = relayd 7607 dovecot 82 0 58036K 10528K CPU16 16 2:31 37.50% auth 3017 root 83 0 19860K 2316K CPU6 6 4:25 36.47% log 3021 dovecot 82 0 23952K 8924K CPU5 5 3:19 34.47% = director 11 root 155 ki31 0K 384K CPU11 11 18.4H 32.96% = idle{idle: cpu11} 11 root 155 ki31 0K 384K RUN 4 18.4H 32.86% = idle{idle: cpu4} 11 root 155 ki31 0K 384K RUN 3 18.4H 32.76% = idle{idle: cpu3} 11 root 155 ki31 0K 384K RUN 2 18.4H 32.67% = idle{idle: cpu2} 11 root 155 ki31 0K 384K RUN 9 18.4H 32.57% = idle{idle: cpu9} 11 root 155 ki31 0K 384K RUN 5 18.4H 32.57% = idle{idle: cpu5} 11 root 155 ki31 0K 384K RUN 0 18.4H 32.37% = idle{idle: cpu0} 11 root 155 ki31 0K 384K CPU22 22 18.3H 32.37% = idle{idle: cpu22} 11 root 155 ki31 0K 384K RUN 7 18.4H 32.28% = idle{idle: cpu7} 11 root 155 ki31 0K 384K CPU14 14 18.3H 32.08% = idle{idle: cpu14} 11 root 155 ki31 0K 384K RUN 6 18.4H 31.88% = idle{idle: cpu6} 11 root 155 ki31 0K 384K RUN 1 18.4H 31.79% = idle{idle: cpu1} 11 root 155 ki31 0K 384K RUN 19 18.3H 31.59% = idle{idle: cpu19} 11 root 155 ki31 0K 384K RUN 8 18.4H 30.96% = idle{idle: cpu8} 7619 dovenull 81 0 59048K 32864K CPU20 20 2:01 30.96% = imap-login 11 root 155 ki31 0K 384K CPU18 18 18.3H 30.76% = idle{idle: cpu18} 11 root 155 ki31 0K 384K RUN 13 18.3H 30.57% = idle{idle: cpu13} 11 root 155 ki31 0K 384K RUN 12 18.3H 30.47% = idle{idle: cpu12} 11 root 155 ki31 0K 384K RUN 20 18.3H 30.08% = idle{idle: cpu20} 11 root 155 ki31 0K 384K RUN 10 18.4H 29.88% = idle{idle: cpu10} 11 root 155 ki31 0K 384K RUN 23 18.3H 29.79% = idle{idle: cpu23} 11 root 155 ki31 0K 384K RUN 15 18.3H 29.59% = idle{idle: cpu15} 11 root 155 ki31 0K 384K RUN 16 18.3H 29.59% = idle{idle: cpu16} 2968 dovenull 52 0 38568K 12240K pipewr 4 5:24 29.39% = pop3-login 11 root 155 ki31 0K 384K RUN 17 18.3H 29.30% = idle{idle: cpu17} 2970 dovenull 52 0 42664K 15968K pipewr 10 7:18 28.66% = pop3-login 2983 dovenull 52 0 38568K 11984K pipewr 5 5:03 28.66% = pop3-login 2976 dovenull 52 0 42664K 17896K pipewr 23 7:46 28.56% = pop3-login 2974 dovenull 52 0 46760K 19156K pipewr 16 7:40 28.47% = pop3-login 2969 dovenull 52 0 38568K 13764K pipewr 12 5:13 28.27% = pop3-login 2990 dovenull 52 0 42664K 16096K pipewr 0 7:22 28.17% = pop3-login 2984 dovenull 52 0 38568K 12796K pipewr 14 5:43 28.08% = pop3-login 2988 dovenull 52 0 42664K 16068K pipewr 2 6:42 27.98% = pop3-login 11 root 155 ki31 0K 384K RUN 21 18.3H 27.88% = idle{idle: cpu21} 2971 dovenull 52 0 38568K 10724K pipewr 0 2:06 27.88% = pop3-login 2989 dovenull 52 0 38568K 12428K pipewr 10 5:21 27.78% = pop3-login 2972 dovenull 52 0 42664K 17876K pipewr 5 7:42 27.69% = pop3-login 2987 dovenull 52 0 42664K 14992K pipewr 16 5:23 27.69% = pop3-login 2981 dovenull 52 0 42664K 16060K pipewr 19 7:32 27.59% = pop3-login [2] last pid: 38598; load averages: 42.11, 22.97, 11.77 = up 0+20:46:40 15:39:38 520 processes: 96 running, 369 sleeping, 55 waiting CPU: 2.8% user, 0.0% nice, 82.3% system, 0.4% interrupt, 14.5% idle Mem: 939M Active, 837M Inact, 3787M Wired, 8K Cache, 7488K Buf, 88G Free ARC: 1884M Total, 108M MRU, 1633M MFU, 914K Anon, 9764K Header, 132M = Other Swap: 8192M Total, 8192M Free PID USERNAME PRI NICE SIZE RES STATE C TIME WCPU = COMMAND 0 root 8 0 0K 3968K CPU20 14 16:09 100.00% = kernel{thread taskq} 2880 _relayd 100 0 65512K 50128K RUN 11 44:06 89.79% = relayd 2881 _relayd 100 0 61416K 44116K RUN 10 8:13 89.45% = relayd 15779 dovenull 98 0 38568K 13236K RUN 17 3:28 86.28% = pop3-login 15771 dovenull 99 0 38568K 12672K RUN 2 5:17 86.08% = pop3-login 15761 dovenull 98 0 38568K 13212K RUN 23 5:15 84.77% = pop3-login 15768 dovenull 99 0 38568K 13268K RUN 12 5:43 84.18% = pop3-login 15775 dovenull 98 0 42664K 14536K RUN 7 4:05 84.08% = pop3-login 17610 dovenull 98 0 50856K 26204K RUN 18 2:09 83.50% = imap-login 16944 dovenull 98 0 54952K 28332K RUN 20 1:42 83.40% = imap-login 15803 dovenull 98 0 67240K 39640K RUN 15 2:48 83.06% = imap-login 15800 dovenull 98 0 63144K 38892K RUN 9 3:15 82.86% = imap-login 20530 dovenull 98 0 63144K 38136K RUN 4 2:57 82.76% = imap-login 12 root -92 - 0K 880K WAIT 0 6:16 82.47% = intr{irq274: ix1:que } 12 root -92 - 0K 880K WAIT 1 6:16 82.37% = intr{irq275: ix1:que } 12 root -92 - 0K 880K WAIT 7 6:05 82.28% = intr{irq281: ix1:que } 12 root -92 - 0K 880K WAIT 2 6:00 82.28% = intr{irq276: ix1:que } 12 root -92 - 0K 880K WAIT 6 5:50 82.28% = intr{irq280: ix1:que } 12 root -60 - 0K 880K WAIT 0 3:20 82.18% = intr{swi4: clock} 12 root -92 - 0K 880K WAIT 4 6:10 82.08% = intr{irq278: ix1:que } 12 root -92 - 0K 880K WAIT 5 5:59 81.98% = intr{irq279: ix1:que } 0 root -92 0 0K 3968K - 23 0:47 81.88% = kernel{ix1 que} 0 root -92 0 0K 3968K - 5 0:43 80.18% = kernel{ix0 que} 17945 root 95 0 16592K 4056K CPU7 0 0:08 75.10% top 15765 dovenull 77 0 46760K 20468K RUN 2 5:41 19.48% = pop3-login 15762 dovenull 78 0 46760K 20708K RUN 20 5:45 19.38% = pop3-login 15773 dovenull 78 0 42664K 14928K RUN 4 3:41 19.38% = pop3-login 15781 dovenull 77 0 42664K 13136K RUN 9 3:01 18.90% = pop3-login 15777 dovenull 77 0 42664K 15840K RUN 1 3:15 18.55% = pop3-login 15772 dovenull 77 0 42664K 14484K RUN 0 5:15 18.46% = pop3-login 15782 dovenull 77 0 38568K 13368K RUN 6 3:20 17.87% = pop3-login 15764 dovenull 77 0 42664K 14816K RUN 20 5:54 17.77% = pop3-login 15759 dovenull 77 0 42664K 16616K RUN 4 1:06 17.77% = pop3-login 15780 dovenull 76 0 42664K 13684K RUN 22 3:19 12.89% = pop3-login [3] db:0:kdb.enter.sysctl> run lockinfo db:1:lockinfo> show locks No such command db:1:locks> show alllocks No such command db:1:alllocks> show lockedvnods Locked vnodes db:0:kdb.enter.sysctl> trace 100058 Tracing pid 0 tid 100058 td 0xfffffe00262fc000 cpustop_handler() at cpustop_handler+0x28 ipi_nmi_handler() at ipi_nmi_handler+0x3d trap() at trap+0x2ea nmi_calltrap() at nmi_calltrap+0x8 --- trap 0x13, rip =3D 0xffffffff809a2a3e, rsp =3D 0xffffff800039efe0, = rbp =3D 0xffffff975cf4aa10 --- unp_gc() at unp_gc+0x20e taskqueue_run_locked() at taskqueue_run_locked+0x85 taskqueue_thread_loop() at taskqueue_thread_loop+0x46 fork_exit() at fork_exit+0x11f fork_trampoline() at fork_trampoline+0xe --- trap 0, rip =3D 0, rsp =3D 0xffffff975cf4abb0, rbp =3D 0 --- db:0:kdb.enter.sysctl> capture off db:0:kdb.enter.sysctl> run lockinfo db:1:lockinfo> show locks No such command db:1:locks> show alllocks No such command db:1:alllocks> show lockedvnods Locked vnodes db:0:kdb.enter.sysctl> trace 100058 Tracing pid 0 tid 100058 td 0xfffffe00262fc000 cpustop_handler() at cpustop_handler+0x28 ipi_nmi_handler() at ipi_nmi_handler+0x3d trap() at trap+0x2ea nmi_calltrap() at nmi_calltrap+0x8 --- trap 0x13, rip =3D 0xffffffff809a29a6, rsp =3D 0xffffff800039efe0, = rbp =3D 0xffffff975cf4aa10 --- unp_gc() at unp_gc+0x176 taskqueue_run_locked() at taskqueue_run_locked+0x85 taskqueue_thread_loop() at taskqueue_thread_loop+0x46 fork_exit() at fork_exit+0x11f fork_trampoline() at fork_trampoline+0xe --- trap 0, rip =3D 0, rsp =3D 0xffffff975cf4abb0, rbp =3D 0 --- db:0:kdb.enter.sysctl> capture off db:0:kdb.enter.sysctl> run lockinfo db:1:lockinfo> show locks No such command db:1:locks> show alllocks No such command db:1:alllocks> show lockedvnods Locked vnodes db:0:kdb.enter.sysctl> trace 100058 Tracing pid 0 tid 100058 td 0xfffffe00262fc000 cpustop_handler() at cpustop_handler+0x28 ipi_nmi_handler() at ipi_nmi_handler+0x3d trap() at trap+0x2ea nmi_calltrap() at nmi_calltrap+0x8 --- trap 0x13, rip =3D 0xffffffff809a2997, rsp =3D 0xffffff80003a5fe0, = rbp =3D 0xffffff975cf4aa10 --- unp_gc() at unp_gc+0x167 taskqueue_run_locked() at taskqueue_run_locked+0x85 taskqueue_thread_loop() at taskqueue_thread_loop+0x46 fork_exit() at fork_exit+0x11f fork_trampoline() at fork_trampoline+0xe --- trap 0, rip =3D 0, rsp =3D 0xffffff975cf4abb0, rbp =3D 0 --- db:0:kdb.enter.sysctl> capture off db:0:kdb.enter.sysctl> run lockinfo db:1:lockinfo> show locks No such command db:1:locks> show alllocks No such command db:1:alllocks> show lockedvnods Locked vnodes db:0:kdb.enter.sysctl> trace 100058 Tracing pid 0 tid 100058 td 0xfffffe00262fc000 cpustop_handler() at cpustop_handler+0x28 ipi_nmi_handler() at ipi_nmi_handler+0x3d trap() at trap+0x2ea nmi_calltrap() at nmi_calltrap+0x8 --- trap 0x13, rip =3D 0xffffffff809a28b1, rsp =3D 0xffffff8000374fe0, = rbp =3D 0xffffff975cf4aa10 --- unp_gc() at unp_gc+0x81 taskqueue_run_locked() at taskqueue_run_locked+0x85 taskqueue_thread_loop() at taskqueue_thread_loop+0x46 fork_exit() at fork_exit+0x11f fork_trampoline() at fork_trampoline+0xe --- trap 0, rip =3D 0, rsp =3D 0xffffff975cf4abb0, rbp =3D 0 --- db:0:kdb.enter.sysctl> capture off db:0:kdb.enter.sysctl> run lockinfo db:1:lockinfo> show locks No such command db:1:locks> show alllocks No such command db:1:alllocks> show lockedvnods Locked vnodes db:0:kdb.enter.sysctl> trace 100058 Tracing pid 0 tid 100058 td 0xfffffe00262fc000 cpustop_handler() at cpustop_handler+0x28 ipi_nmi_handler() at ipi_nmi_handler+0x3d trap() at trap+0x2ea nmi_calltrap() at nmi_calltrap+0x8 --- trap 0x13, rip =3D 0xffffffff809a28b1, rsp =3D 0xffffff80003b3fe0, = rbp =3D 0xffffff975cf4aa10 --- unp_gc() at unp_gc+0x81 taskqueue_run_locked() at taskqueue_run_locked+0x85 taskqueue_thread_loop() at taskqueue_thread_loop+0x46 fork_exit() at fork_exit+0x11f fork_trampoline() at fork_trampoline+0xe --- trap 0, rip =3D 0, rsp =3D 0xffffff975cf4abb0, rbp =3D 0 --- db:0:kdb.enter.sysctl> capture off [4] db:0:lockedvnods> show pcpu cpuid =3D 0 dynamic pcpu =3D 0x800380 curthread =3D 0xfffffe00264b8000: pid 12 "irq265: ix0:que 0" curpcb =3D 0xffffff9a3ea71bc0 fpcurthread =3D none idlethread =3D 0xfffffe00262bc470: tid 100003 "idle: cpu0" curpmap =3D 0xffffffff812d5af0 tssp =3D 0xffffffff814e0960 commontssp =3D 0xffffffff814e0960 rsp0 =3D 0xffffff9a3ea71bc0 gs32p =3D 0xffffffff814deab8 ldt =3D 0xffffffff814deaf8 tss =3D 0xffffffff814deae8 spin locks held: db:0:pcpu> bt Tracing pid 12 tid 100069 td 0xfffffe00264b8000 kdb_enter() at kdb_enter+0x3b panic() at panic+0x1d1 soabort() at soabort+0x99 syncache_expand() at syncache_expand+0x306 tcp_input() at tcp_input+0x1033 ip_input() at ip_input+0xbd netisr_dispatch_src() at netisr_dispatch_src+0x152 ether_demux() at ether_demux+0x17d ether_nh_input() at ether_nh_input+0x20e netisr_dispatch_src() at netisr_dispatch_src+0x152 ether_demux() at ether_demux+0x86 ether_nh_input() at ether_nh_input+0x20e netisr_dispatch_src() at netisr_dispatch_src+0x152 ixgbe_rxeof() at ixgbe_rxeof+0x1b9 ixgbe_msix_que() at ixgbe_msix_que+0x8d intr_event_execute_handlers() at intr_event_execute_handlers+0x6a ithread_loop() at ithread_loop+0xb4 fork_exit() at fork_exit+0x135 fork_trampoline() at fork_trampoline+0xe [5] FreeBSD XY.hostpoint.net 9.1-RC3 FreeBSD 9.1-RC3 #4 r242695: Wed Nov 7 = 11:33:17 UTC 2012 = root@XY.hostpoint.ch:/usr/obj/usr/src/sys/HOSTPOINT amd64 kernconf: ---- include GENERIC ident HOSTPOINT # ipfw options IPFIREWALL options IPFIREWALL_VERBOSE options IPFIREWALL_VERBOSE_LIMIT=3D5 options IPFIREWALL_DEFAULT_TO_ACCEPT options IPFIREWALL_FORWARD options IPDIVERT # ddb for debugging and textdumps options KDB # Enable kernel debugger support. options DDB # Support DDB. # dtrace options KDTRACE_HOOKS # all architectures - enable general = DTrace hooks options DDB_CTF # all architectures - kernel ELF = linker loads CTF data options KDTRACE_FRAME # amd64-only makeoptions DEBUG=3D"-g" makeoptions WITH_CTF=3D1 ---- dmesg boot: ---- Copyright (c) 1992-2012 The FreeBSD Project. Copyright (c) 1979, 1980, 1983, 1986, 1988, 1989, 1991, 1992, 1993, 1994 The Regents of the University of California. All rights = reserved. FreeBSD is a registered trademark of The FreeBSD Foundation. FreeBSD 9.1-RC3 #4 r242695: Wed Nov 7 11:33:17 UTC 2012 root@XY.hostpoint.ch:/usr/obj/usr/src/sys/HOSTPOINT amd64 CPU: Intel(R) Xeon(R) CPU E5-2440 0 @ 2.40GHz (2400.05-MHz K8-class CPU) Origin =3D "GenuineIntel" Id =3D 0x206d7 Family =3D 6 Model =3D 2d = Stepping =3D 7 = Features=3D0xbfebfbff = Features2=3D0x1fbee3ff AMD Features=3D0x2c100800 AMD Features2=3D0x1 TSC: P-state invariant, performance statistics real memory =3D 103079215104 (98304 MB) avail memory =3D 99335512064 (94733 MB) Event timer "LAPIC" quality 600 ACPI APIC Table: FreeBSD/SMP: Multiprocessor System Detected: 24 CPUs FreeBSD/SMP: 2 package(s) x 6 core(s) x 2 SMT threads cpu0 (BSP): APIC ID: 0 cpu1 (AP): APIC ID: 1 cpu2 (AP): APIC ID: 2 cpu3 (AP): APIC ID: 3 cpu4 (AP): APIC ID: 4 cpu5 (AP): APIC ID: 5 cpu6 (AP): APIC ID: 6 cpu7 (AP): APIC ID: 7 cpu8 (AP): APIC ID: 8 cpu9 (AP): APIC ID: 9 cpu10 (AP): APIC ID: 10 cpu11 (AP): APIC ID: 11 cpu12 (AP): APIC ID: 32 cpu13 (AP): APIC ID: 33 cpu14 (AP): APIC ID: 34 cpu15 (AP): APIC ID: 35 cpu16 (AP): APIC ID: 36 cpu17 (AP): APIC ID: 37 cpu18 (AP): APIC ID: 38 cpu19 (AP): APIC ID: 39 cpu20 (AP): APIC ID: 40 cpu21 (AP): APIC ID: 41 cpu22 (AP): APIC ID: 42 cpu23 (AP): APIC ID: 43 Security policy loaded: TrustedBSD MAC/seeotheruids (mac_seeotheruids) ioapic1: Changing APIC ID to 1 ioapic2: Changing APIC ID to 2 ioapic0 irqs 0-23 on motherboard ioapic1 irqs 32-55 on motherboard ioapic2 irqs 64-87 on motherboard kbd1 at kbdmux0 acpi0: on motherboard acpi0: Power Button (fixed) cpu0: on acpi0 cpu1: on acpi0 cpu2: on acpi0 cpu3: on acpi0 cpu4: on acpi0 cpu5: on acpi0 cpu6: on acpi0 cpu7: on acpi0 cpu8: on acpi0 cpu9: on acpi0 cpu10: on acpi0 cpu11: on acpi0 cpu12: on acpi0 cpu13: on acpi0 cpu14: on acpi0 cpu15: on acpi0 cpu16: on acpi0 cpu17: on acpi0 cpu18: on acpi0 cpu19: on acpi0 cpu20: on acpi0 cpu21: on acpi0 cpu22: on acpi0 cpu23: on acpi0 atrtc0: port 0x70-0x7f irq 8 on acpi0 Event timer "RTC" frequency 32768 Hz quality 0 attimer0: port 0x40-0x5f irq 0 on acpi0 Timecounter "i8254" frequency 1193182 Hz quality 0 Event timer "i8254" frequency 1193182 Hz quality 100 hpet0: iomem 0xfed00000-0xfed003ff on acpi0 Timecounter "HPET" frequency 14318180 Hz quality 950 Event timer "HPET" frequency 14318180 Hz quality 450 Event timer "HPET1" frequency 14318180 Hz quality 440 Event timer "HPET2" frequency 14318180 Hz quality 440 Event timer "HPET3" frequency 14318180 Hz quality 440 Event timer "HPET4" frequency 14318180 Hz quality 440 Event timer "HPET5" frequency 14318180 Hz quality 440 Event timer "HPET6" frequency 14318180 Hz quality 440 Event timer "HPET7" frequency 14318180 Hz quality 440 Timecounter "ACPI-fast" frequency 3579545 Hz quality 900 acpi_timer0: <24-bit timer at 3.579545MHz> port 0x808-0x80b on acpi0 pcib0: port 0xcf8-0xcff on acpi0 pci0: on pcib0 pcib1: irq 53 at device 1.0 on pci0 pci1: on pcib1 mfi0: port 0xfc00-0xfcff mem = 0xdcffc000-0xdcffffff,0xdcf80000-0xdcfbffff irq 34 at device 0.0 on pci1 mfi0: Using MSI mfi0: Megaraid SAS driver Ver 4.23=20 mfi0: MaxCmd =3D 3f0 MaxSgl =3D 46 state =3D b73c03f0=20 pcib2: irq 53 at device 3.0 on pci0 pci8: on pcib2 ix0: = mem 0xd9000000-0xd91fffff,0xd95f8000-0xd95fbfff irq 52 at device 0.0 on = pci8 ix0: Using MSIX interrupts with 9 vectors ix0: Ethernet address: a0:36:9f:08:cd:4c ix0: PCI Express Bus: Speed 5.0Gb/s Width x8 ix1: = mem 0xd9200000-0xd93fffff,0xd95fc000-0xd95fffff irq 48 at device 0.1 on = pci8 ix1: Using MSIX interrupts with 9 vectors ix1: Ethernet address: a0:36:9f:08:cd:4e ix1: PCI Express Bus: Speed 5.0Gb/s Width x8 pci0: at device 5.0 (no driver attached) pci0: at device 5.2 (no driver attached) pcib3: irq 16 at device 17.0 on pci0 pci9: on pcib3 pci0: at device 22.0 (no driver attached) pci0: at device 22.1 (no driver attached) ehci0: mem 0xdf8fd000-0xdf8fd3ff irq = 23 at device 26.0 on pci0 usbus0: EHCI version 1.0 usbus0 on ehci0 pcib4: at device 28.0 on pci0 pci10: on pcib4 pcib5: irq 16 at device 28.4 on pci0 pci2: on pcib5 bge0: mem = 0xd96a0000-0xd96affff,0xd96b0000-0xd96bffff,0xd96c0000-0xd96cffff irq 16 = at device 0.0 on pci2 bge0: CHIP ID 0x05720000; ASIC REV 0x5720; CHIP REV 0x57200; PCI-E bge0: Try again miibus0: on bge0 brgphy0: PHY 1 on miibus0 brgphy0: 10baseT, 10baseT-FDX, 100baseTX, 100baseTX-FDX, 1000baseT, = 1000baseT-master, 1000baseT-FDX, 1000baseT-FDX-master, auto, auto-flow bge0: Ethernet address: d4:ae:52:a4:3c:de bge1: mem = 0xd96d0000-0xd96dffff,0xd96e0000-0xd96effff,0xd96f0000-0xd96fffff irq 17 = at device 0.1 on pci2 bge1: CHIP ID 0x05720000; ASIC REV 0x5720; CHIP REV 0x57200; PCI-E miibus1: on bge1 brgphy1: PHY 2 on miibus1 brgphy1: 10baseT, 10baseT-FDX, 100baseTX, 100baseTX-FDX, 1000baseT, = 1000baseT-master, 1000baseT-FDX, 1000baseT-FDX-master, auto, auto-flow bge1: Ethernet address: d4:ae:52:a4:3c:df pcib6: irq 19 at device 28.7 on pci0 pci3: on pcib6 pcib7: at device 0.0 on pci3 pci4: on pcib7 pcib8: at device 0.0 on pci4 pci5: on pcib8 pcib9: at device 0.0 on pci5 pci6: on pcib9 vgapci0: mem = 0xd8000000-0xd8ffffff,0xdeffc000-0xdeffffff,0xde000000-0xde7fffff irq 19 = at device 0.0 on pci6 pcib10: at device 1.0 on pci4 pci7: on pcib10 ehci1: mem 0xdf8fe000-0xdf8fe3ff irq = 22 at device 29.0 on pci0 usbus1: EHCI version 1.0 usbus1 on ehci1 pcib11: at device 30.0 on pci0 pci11: on pcib11 isab0: at device 31.0 on pci0 isa0: on isab0 ahci0: port = 0xece8-0xecef,0xecf8-0xecfb,0xecf0-0xecf7,0xecfc-0xecff,0xecc0-0xecdf = mem 0xdf8ff000-0xdf8ff7ff irq 20 at device 31.2 on pci0 ahci0: AHCI v1.30 with 6 3Gbps ports, Port Multiplier not supported ahcich0: at channel 0 on ahci0 ahcich1: at channel 1 on ahci0 ahcich2: at channel 2 on ahci0 ahcich3: at channel 3 on ahci0 ahcich4: at channel 4 on ahci0 pcib12: on acpi0 pci64: on pcib12 pcib13: irq 85 at device 3.0 on pci64 pci65: on pcib13 pci64: at device 5.0 (no driver attached) pci64: at device 5.2 (no driver attached) pcib14: on acpi0 pci63: on pcib14 pci63: at device 8.0 (no driver attached) pci63: at device 9.0 (no driver attached) pci63: at device 10.0 (no driver attached) pci63: at device 10.1 (no driver attached) pci63: at device 10.2 (no driver attached) pci63: at device 10.3 (no driver attached) pci63: at device 11.0 (no driver attached) pci63: at device 11.3 (no driver attached) pci63: at device 12.0 (no driver attached) pci63: at device 12.1 (no driver attached) pci63: at device 12.2 (no driver attached) pci63: at device 12.6 (no driver attached) pci63: at device 12.7 (no driver attached) pci63: at device 13.0 (no driver attached) pci63: at device 13.1 (no driver attached) pci63: at device 13.2 (no driver attached) pci63: at device 13.6 (no driver attached) pci63: at device 14.0 (no driver attached) pci63: at device 14.1 (no driver attached) pci63: at device 15.0 (no driver attached) pci63: at device 15.1 (no driver attached) pci63: at device 15.2 (no driver attached) pci63: at device 15.3 (no driver attached) pci63: at device 15.4 (no driver attached) pci63: at device 15.5 (no driver attached) pci63: at device 15.6 (no driver attached) pci63: at device 16.0 (no driver attached) pci63: at device 16.1 (no driver attached) pci63: at device 16.2 (no driver attached) pci63: at device 16.3 (no driver attached) pci63: at device 16.5 (no driver attached) pci63: at device 16.6 (no driver attached) pci63: at device 16.7 (no driver attached) pci63: at device 17.0 (no driver attached) pci63: at device 19.0 (no driver attached) pci63: at device 19.1 (no driver attached) pci63: at device 19.4 (no driver attached) pci63: at device 19.5 (no driver attached) pci63: at device 19.6 (no driver attached) pcib15: on acpi0 pci127: on pcib15 pci127: at device 8.0 (no driver attached) pci127: at device 9.0 (no driver attached) pci127: at device 10.0 (no driver attached) pci127: at device 10.1 (no driver attached) pci127: at device 10.2 (no driver attached) pci127: at device 10.3 (no driver attached) pci127: at device 11.0 (no driver attached) pci127: at device 11.3 (no driver attached) pci127: at device 12.0 (no driver attached) pci127: at device 12.1 (no driver attached) pci127: at device 12.2 (no driver attached) pci127: at device 12.6 (no driver attached) pci127: at device 12.7 (no driver attached) pci127: at device 13.0 (no driver attached) pci127: at device 13.1 (no driver attached) pci127: at device 13.2 (no driver attached) pci127: at device 13.6 (no driver attached) pci127: at device 14.0 (no driver attached) pci127: at device 14.1 (no driver attached) pci127: at device 15.0 (no driver attached) pci127: at device 15.1 (no driver attached) pci127: at device 15.2 (no driver attached) pci127: at device 15.3 (no driver attached) pci127: at device 15.4 (no driver attached) pci127: at device 15.5 (no driver attached) pci127: at device 15.6 (no driver attached) pci127: at device 16.0 (no driver attached) pci127: at device 16.1 (no driver attached) pci127: at device 16.2 (no driver attached) pci127: at device 16.3 (no driver attached) pci127: at device 16.5 (no driver attached) pci127: at device 16.6 (no driver attached) pci127: at device 16.7 (no driver attached) pci127: at device 17.0 (no driver attached) pci127: at device 19.0 (no driver attached) pci127: at device 19.1 (no driver attached) pci127: at device 19.4 (no driver attached) pci127: at device 19.5 (no driver attached) pci127: at device 19.6 (no driver attached) uart1: <16550 or compatible> port 0x2f8-0x2ff irq 3 on acpi0 uart0: <16550 or compatible> port 0x3f8-0x3ff irq 4 flags 0x10 on acpi0 uart0: console (9600,n,8,1) orm0: at iomem = 0xc0000-0xc7fff,0xcc000-0xccfff,0xec000-0xeffff on isa0 sc0: at flags 0x100 on isa0 sc0: VGA <16 virtual consoles, flags=3D0x300> vga0: at port 0x3c0-0x3df iomem 0xa0000-0xbffff on = isa0 ppc0: cannot reserve I/O port range ctl: CAM Target Layer loaded est0: on cpu0 est: CPU supports Enhanced Speedstep, but is not recognized. est: cpu_vendor GenuineIntel, msr 23b500001b00 device_attach: est0 attach returned 6 p4tcc0: on cpu0 est1: on cpu1 est: CPU supports Enhanced Speedstep, but is not recognized. est: cpu_vendor GenuineIntel, msr 23b500001b00 device_attach: est1 attach returned 6 p4tcc1: on cpu1 est2: on cpu2 est: CPU supports Enhanced Speedstep, but is not recognized. est: cpu_vendor GenuineIntel, msr 23b500001b00 device_attach: est2 attach returned 6 p4tcc2: on cpu2 est3: on cpu3 est: CPU supports Enhanced Speedstep, but is not recognized. est: cpu_vendor GenuineIntel, msr 23b500001b00 device_attach: est3 attach returned 6 p4tcc3: on cpu3 est4: on cpu4 est: CPU supports Enhanced Speedstep, but is not recognized. est: cpu_vendor GenuineIntel, msr 23b500001b00 device_attach: est4 attach returned 6 p4tcc4: on cpu4 est5: on cpu5 est: CPU supports Enhanced Speedstep, but is not recognized. est: cpu_vendor GenuineIntel, msr 23b500001b00 device_attach: est5 attach returned 6 p4tcc5: on cpu5 est6: on cpu6 est: CPU supports Enhanced Speedstep, but is not recognized. est: cpu_vendor GenuineIntel, msr 23b500001b00 device_attach: est6 attach returned 6 p4tcc6: on cpu6 est7: on cpu7 est: CPU supports Enhanced Speedstep, but is not recognized. est: cpu_vendor GenuineIntel, msr 23b500001b00 device_attach: est7 attach returned 6 p4tcc7: on cpu7 est8: on cpu8 est: CPU supports Enhanced Speedstep, but is not recognized. est: cpu_vendor GenuineIntel, msr 23b500001b00 device_attach: est8 attach returned 6 p4tcc8: on cpu8 est9: on cpu9 est: CPU supports Enhanced Speedstep, but is not recognized. est: cpu_vendor GenuineIntel, msr 23b500001b00 device_attach: est9 attach returned 6 p4tcc9: on cpu9 est10: on cpu10 est: CPU supports Enhanced Speedstep, but is not recognized. est: cpu_vendor GenuineIntel, msr 23b500001b00 device_attach: est10 attach returned 6 p4tcc10: on cpu10 est11: on cpu11 est: CPU supports Enhanced Speedstep, but is not recognized. est: cpu_vendor GenuineIntel, msr 23b500001b00 device_attach: est11 attach returned 6 p4tcc11: on cpu11 est12: on cpu12 est: CPU supports Enhanced Speedstep, but is not recognized. est: cpu_vendor GenuineIntel, msr 23b500001b00 device_attach: est12 attach returned 6 p4tcc12: on cpu12 est13: on cpu13 est: CPU supports Enhanced Speedstep, but is not recognized. est: cpu_vendor GenuineIntel, msr 23b500001b00 device_attach: est13 attach returned 6 p4tcc13: on cpu13 est14: on cpu14 est: CPU supports Enhanced Speedstep, but is not recognized. est: cpu_vendor GenuineIntel, msr 23b500001b00 device_attach: est14 attach returned 6 p4tcc14: on cpu14 est15: on cpu15 est: CPU supports Enhanced Speedstep, but is not recognized. est: cpu_vendor GenuineIntel, msr 23b500001b00 device_attach: est15 attach returned 6 p4tcc15: on cpu15 est16: on cpu16 est: CPU supports Enhanced Speedstep, but is not recognized. est: cpu_vendor GenuineIntel, msr 23b500001b00 device_attach: est16 attach returned 6 p4tcc16: on cpu16 est17: on cpu17 est: CPU supports Enhanced Speedstep, but is not recognized. est: cpu_vendor GenuineIntel, msr 23b500001b00 device_attach: est17 attach returned 6 p4tcc17: on cpu17 est18: on cpu18 est: CPU supports Enhanced Speedstep, but is not recognized. est: cpu_vendor GenuineIntel, msr 23b500001b00 device_attach: est18 attach returned 6 p4tcc18: on cpu18 est19: on cpu19 est: CPU supports Enhanced Speedstep, but is not recognized. est: cpu_vendor GenuineIntel, msr 23b500001b00 device_attach: est19 attach returned 6 p4tcc19: on cpu19 est20: on cpu20 est: CPU supports Enhanced Speedstep, but is not recognized. est: cpu_vendor GenuineIntel, msr 23b500001b00 device_attach: est20 attach returned 6 p4tcc20: on cpu20 est21: on cpu21 est: CPU supports Enhanced Speedstep, but is not recognized. est: cpu_vendor GenuineIntel, msr 23b500001b00 device_attach: est21 attach returned 6 p4tcc21: on cpu21 est22: on cpu22 est: CPU supports Enhanced Speedstep, but is not recognized. est: cpu_vendor GenuineIntel, msr 23b500001b00 device_attach: est22 attach returned 6 p4tcc22: on cpu22 est23: on cpu23 est: CPU supports Enhanced Speedstep, but is not recognized. est: cpu_vendor GenuineIntel, msr 23b500001b00 device_attach: est23 attach returned 6 p4tcc23: on cpu23 ZFS filesystem version 5 ZFS storage pool version 28 Timecounters tick every 1.000 msec ipfw2 (+ipv6) initialized, divert enabled, nat loadable, rule-based = forwarding enabled, default to accept, logging disabled mfi0: 1828 (406136473s/0x0020/info) - Shutdown command received from = host mfi0: 1829 (boot + 4s/0x0020/info) - Firmware initialization started = (PCI ID 005b/1000/1f38/1028) mfi0: 1830 (boot + 4s/0x0020/info) - Firmware version 3.130.05-1587 mfi0: 1831 (boot + 5s/0x0008/info) - Battery Present mfi0: 1832 (boot + 5s/0x0020/info) - Package version 21.0.2-0001 mfi0: 1833 (boot + 5s/0x0020/info) - Board Revision A00 mfi0: 1834 (boot + 19s/0x0004/info) - Enclosure PD 20(c None/p1) = communication restored mfi0: 1835 (boot + 19s/0x0002/info) - Inserted: Encl PD 20 usbus0: 480Mbps High Speed USB v2.0 usbus1: 480Mbps High Speed USB v2.0 ugen0.1: at usbus0 uhub0: on usbus0 ugen1.1: at usbus1 uhub1: on usbus1 mfid0 on mfi0 mfid0: 285568MB (584843264 sectors) RAID volume (no label) is optimal mfid1 on mfi0 mfid1: 285568MB (584843264 sectors) RAID volume (no label) is optimal mfi0: 1836 (boot + 19s/0x0002/info) - Inserted: PD 20(c None/p1) Info: = enclPd=3D20, scsiType=3Dd, portMap=3D00, = sasAddr=3D5e4ae020b6ff2c00,0000000000000000 mfi0: 1837 (boot + 19s/0x0002/info) - Inserted: PD 00(e0x20/s0) mfi0: 1838 (boot + 19s/0x0002/info) - Inserted: PD 00(e0x20/s0) Info: = enclPd=3D20, scsiType=3D0, portMap=3D00, = sasAddr=3D5000c50054b863ad,0000000000000000 mfi0: 1839 (boot + 19s/0x0002/info) - Inserted: PD 01(e0x20/s1) mfi0: 1840 (boot + 19s/0x0002/info) - Inserted: PD 01(e0x20/s1) Info: = enclPd=3D20, scsiType=3D0, portMap=3D01, = sasAddr=3D5000c50054b62409,0000000000000000 mfi0: 1841 (406136547s/0x0020/info) - Time established as 11/13/12 = 15:42:27; (53 seconds since power on) mfi0: 1842 (406136564s/0x0008/info) - Battery temperature is normal uhub0: 2 ports with 2 removable, self powered uhub1: 2 ports with 2 removable, self powered mfi0: 1843 (406136564s/0x0008/info) - Current capacity of the battery is = above threshold mfi0: 1844 (406136789s/0x0020/info) - Host driver is loaded and = operational ugen0.2: at usbus0 uhub2: = on usbus0 ugen1.2: at usbus1 uhub3: = on usbus1 SMP: AP CPU #1 Launched! SMP: AP CPU #20 Launched! SMP: AP CPU #9 Launched! SMP: AP CPU #15 Launched! SMP: AP CPU #4 Launched! SMP: AP CPU #7 Launched! SMP: AP CPU #10 Launched! SMP: AP CPU #14 Launched! SMP: AP CPU #6 Launched! SMP: AP CPU #23 Launched! SMP: AP CPU #2 Launched! SMP: AP CPU #8 Launched! SMP: AP CPU #22 Launched! SMP: AP CPU #17 Launched! SMP: AP CPU #5 Launched! SMP: AP CPU #3 Launched! SMP: AP CPU #21 Launched! SMP: AP CPU #16 Launched! SMP: AP CPU #12 Launched! SMP: AP CPU #13 Launched! SMP: AP CPU #19 Launched! SMP: AP CPU #11 Launched! SMP: AP CPU #18 Launched! Timecounter "TSC-low" frequency 9375184 Hz quality 1000 Root mount waiting for: usbus1 usbus0 uhub2: 6 ports with 6 removable, self powered uhub3: 8 ports with 8 removable, self powered ugen0.3: at usbus0 uhub4: on usbus0 Root mount waiting for: usbus0 uhub4: 6 ports with 6 removable, self powered ugen0.4: at usbus0 ukbd0: on usbus0 kbd0 at ukbd0 ums0: on usbus0 ums0: 3 buttons and [Z] coordinates ID=3D0 ums1: on usbus0 Root mount waiting for: usbus0 ums1: 3 buttons and [XYZ] coordinates ID=3D0 Root mount waiting for: usbus0 ugen0.5: at usbus0 umass0: on usbus0 umass0: SCSI over Bulk-Only; quirks =3D 0x0000 umass0:6:0:-1: Attached to scbus6 cd0 at umass-sim0 bus 0 scbus6 target 0 lun 0 cd0: Removable CD-ROM SCSI-0 device=20 cd0: 40.000MB/s transfers cd0: Attempt to query device size failed: NOT READY, Medium not present da0 at umass-sim0 bus 0 scbus6 target 0 lun 1 da0: Removable Direct Access SCSI-0 device=20= da0: 40.000MB/s transfers da0: 524MB (1073741 512 byte sectors: 64H 32S/T 524C) Trying to mount root from zfs:zroot []... ix0: 2 link states coalesced ix1: 2 link states coalesced ix0: 2 link states coalesced ---- network related loader.conf settings: ---- dev.bge.0.msi=3D"0" dev.bge.1.msi=3D"0" net.inet.tcp.syncache.hashsize=3D32768 net.inet.tcp.syncache.bucketlimit=3D32 net.inet.tcp.syncache.cachelimit=3D1048576 net.inet.tcp.tcbhashsize=3D1048576 net.inet.tcp.hostcache.hashsize=3D65536 net.inet.tcp.hostcache.cachelimit=3D1966080 ---- network related part of sysctl.conf: ---- net.inet.ip.fw.verbose=3D0 net.inet.ip.redirect=3D0 net.inet.icmp.drop_redirect=3D1 net.inet.tcp.drop_synfin=3D1 #net.inet.tcp.icmp_may_rst=3D0 #net.inet.udp.blackhole=3D1 #net.inet.tcp.blackhole=3D2 net.inet6.ip6.accept_rtadv=3D0 net.inet6.icmp6.rediraccept=3D0 kern.ipc.maxsockets=3D1000000 net.inet.tcp.maxtcptw=3D200000 kern.ipc.nmbclusters=3D262144 net.inet.tcp.recvspace=3D65536 net.inet.tcp.sendspace=3D65536 kern.ipc.somaxconn=3D10240 net.inet.ip.portrange.first=3D2048 net.inet.ip.portrange.last=3D65535 net.inet.tcp.msl=3D5000 net.inet.tcp.fast_finwait2_recycle=3D1 net.inet.ip.intr_queue_maxlen=3D4096 #net.inet.tcp.ecn.enable=3D1 net.inet.icmp.icmplim=3D5000 ----