From owner-freebsd-net@FreeBSD.ORG Sat Oct 18 06:32:14 2014 Return-Path: Delivered-To: freebsd-net@freebsd.org Received: from mx1.freebsd.org (mx1.freebsd.org [IPv6:2001:1900:2254:206a::19:1]) (using TLSv1.2 with cipher AECDH-AES256-SHA (256/256 bits)) (No client certificate requested) by hub.freebsd.org (Postfix) with ESMTPS id 8E2F862A; Sat, 18 Oct 2014 06:32:14 +0000 (UTC) Received: from mail-oi0-x232.google.com (mail-oi0-x232.google.com [IPv6:2607:f8b0:4003:c06::232]) (using TLSv1 with cipher ECDHE-RSA-RC4-SHA (128/128 bits)) (Client CN "smtp.gmail.com", Issuer "Google Internet Authority G2" (verified OK)) by mx1.freebsd.org (Postfix) with ESMTPS id 4E2208A3; Sat, 18 Oct 2014 06:32:14 +0000 (UTC) Received: by mail-oi0-f50.google.com with SMTP id i138so1554003oig.23 for ; Fri, 17 Oct 2014 23:32:13 -0700 (PDT) DKIM-Signature: v=1; a=rsa-sha256; c=relaxed/relaxed; d=gmail.com; s=20120113; h=mime-version:in-reply-to:references:date:message-id:subject:from:to :cc:content-type; bh=/gqZjIbdPA5XTumcCvXb6qOTGdTVR72ptU1ltu+YG90=; b=Q3UwQlIqCHTqi2L5yJ65vsjXQpprEKVsmqIKSVazX9VqycgoArZna4kW6dOSVUqyN8 5NtEdH57U8mguWQyJq7wVdBXAShUq3GC6wGwwRTdxvMGkzPXZW40fIIz7gAWRz3OavoY L8tIC+BF1iuZ6l9k+BF2pj0/3e+F8gaCFvhT6PWeHbbWwF85Y0r6SQjIrtsra0ZfKcrA omdbjZgdLAHGfa5/fFMqOqPlHVs69uD8/LSdV7kMG2M868/+AIUfPbL+30WAZLaK1oH3 XLl/y3t+NgNM0vZeU7Gt7QY/bmRaZ+QoRkfXzDmHSLQRyxPPltBNVqXSGvzDGwEaTL1n lEdA== MIME-Version: 1.0 X-Received: by 10.202.211.133 with SMTP id k127mr555994oig.53.1413613933583; Fri, 17 Oct 2014 23:32:13 -0700 (PDT) Received: by 10.202.200.196 with HTTP; Fri, 17 Oct 2014 23:32:13 -0700 (PDT) In-Reply-To: <201410161523.32415.jhb@freebsd.org> References: <1410203348.1343.1.camel@bruno> <3567780.Mf6fMnzmYG@ralph.baldwin.cx> <201410161523.32415.jhb@freebsd.org> Date: Fri, 17 Oct 2014 23:32:13 -0700 Message-ID: Subject: Re: ixgbe(4) spin lock held too long From: Jason Wolfe To: John Baldwin Content-Type: text/plain; charset=UTF-8 Cc: Sean Bruno , freebsd-net@freebsd.org X-BeenThere: freebsd-net@freebsd.org X-Mailman-Version: 2.1.18-1 Precedence: list List-Id: Networking and TCP/IP with FreeBSD List-Unsubscribe: , List-Archive: List-Post: List-Help: List-Subscribe: , X-List-Received-Date: Sat, 18 Oct 2014 06:32:14 -0000 On Thu, Oct 16, 2014 at 12:23 PM, John Baldwin wrote: > > > I looked at the other trace and I don't think it disagrees with my previous > theory. I do have more KTR patches to log when we spin on locks which would > really confirm this, but I haven't tested those fully on HEAD yet. > > However, I'd rather spend time debugging this panic. I think I added that > assertion myself. > > The root problem is that the persist and retransmit timers share state, > so only one should ever be active at a time. In this case, the persist > timer has fired and is rescheduling itself, but some other thread has > scheduled the retransmit timer to fire. The bug is probably in that other > thread. It should either not scheduled the retransmit timer, or it should > first cancel the persist timer. > > A new assertion should be able to find this. Note, this is definitely going > to panic, but one panic is probably enough to find this. > > Index: tcp_timer.c > =================================================================== > --- tcp_timer.c (revision 272718) > +++ tcp_timer.c (working copy) > @@ -713,10 +713,14 @@ tcp_timer_activate(struct tcpcb *tp, int timer_typ > case TT_REXMT: > t_callout = &tp->t_timers->tt_rexmt; > f_callout = tcp_timer_rexmt; > + if (callout_active(&tp->t_timers->tt_persist)) > + panic("scheduling retransmit with persist active"); > break; > case TT_PERSIST: > t_callout = &tp->t_timers->tt_persist; > f_callout = tcp_timer_persist; > + if (callout_active(&tp->t_timers->tt_rexmt)) > + panic("scheduling persist with retransmit active"); > break; > case TT_KEEP: > t_callout = &tp->t_timers->tt_keep; > > -- > John Baldwin Producing 10G of random traffic against a server with this assertion added took about 2 hours to panic, so if it turns out we need anything further it should be pretty quick. #1 0xffffffff806facb1 in kern_reboot (howto=260) at /usr/src/sys/kern/kern_shutdown.c:452 #2 0xffffffff806fb014 in panic (fmt=) at /usr/src/sys/kern/kern_shutdown.c:759 #3 0xffffffff8084edba in tcp_timer_activate (tp=0x0, timer_type=, delta=0) at /usr/src/sys/netinet/tcp_timer.c:695 #4 0xffffffff80841bad in tcp_do_segment (m=0xfffff80019898d00, th=0xfffff80019898d82, so=0xfffff8026cafaae0, tp=, drop_hdrlen=, tlen=0, iptos=, ti_locked=-2047) at /usr/src/sys/netinet/tcp_input.c:2821 #5 0xffffffff8083f748 in tcp_input (m=, off0=) at /usr/src/sys/netinet/tcp_input.c:1388 #6 0xffffffff807dc707 in ip_input (m=0xfffff80019898d00) at /usr/src/sys/netinet/ip_input.c:734 #7 0xffffffff807b8a61 in netisr_dispatch_src (proto=, source=, m=0x0) at /usr/src/sys/net/netisr.c:972 #8 0xffffffff807b1f06 in ether_demux (ifp=, m=0xfffff80019898d00) at /usr/src/sys/net/if_ethersubr.c:851 #9 0xffffffff807b2b99 in ether_nh_input (m=) at /usr/src/sys/net/if_ethersubr.c:646 #10 0xffffffff807b8a61 in netisr_dispatch_src (proto=, source=, m=0x0) at /usr/src/sys/net/netisr.c:972 #11 0xffffffff80843f68 in tcp_lro_flush (lc=0xfffff8000e6f7188, le=0xfffff80019335380) at /usr/src/sys/netinet/tcp_lro.c:301 #12 0xffffffff80844563 in tcp_lro_rx (lc=0x0, m=, csum=) at /usr/src/sys/netinet/tcp_lro.c:515 #13 0xffffffff804a6622 in ixgbe_rxeof (que=0xfffff8000e702068) at /usr/src/sys/dev/ixgbe/ixgbe.c:4356 #14 0xffffffff804a6cd9 in ixgbe_msix_que (arg=0xfffff8000e702068) at /usr/src/sys/dev/ixgbe/ixgbe.c:1523 #15 0xffffffff806d16f3 in intr_event_execute_handlers (p=, ie=0xfffff8000e6fcb00) at /usr/src/sys/kern/kern_intr.c:1263 ---Type to continue, or q to quit--- #16 0xffffffff806d2056 in ithread_loop (arg=0xfffff8000e719ac0) at /usr/src/sys/kern/kern_intr.c:1276 #17 0xffffffff806cf481 in fork_exit (callout=0xffffffff806d1fc0 , arg=0xfffff8000e719ac0, frame=0xfffffe0f9558cac0) at /usr/src/sys/kern/kern_fork.c:996 #4 list 2816 * timer and remember to restart (more output or persist). 2817 * If there is more data to be acked, restart retransmit 2818 * timer, using current (possibly backed-off) value. 2819 */ 2820 if (th->th_ack == tp->snd_max) { 2821 tcp_timer_activate(tp, TT_REXMT, 0); 2822 needoutput = 1; 2823 } else if (!tcp_timer_active(tp, TT_PERSIST)) 2824 tcp_timer_activate(tp, TT_REXMT, tp->t_rxtcur); #5 list 1383 /* 1384 * Segment belongs to a connection in SYN_SENT, ESTABLISHED or later 1385 * state. tcp_do_segment() always consumes the mbuf chain, unlocks 1386 * the inpcb, and unlocks pcbinfo. 1387 */ 1388 tcp_do_segment(m, th, so, tp, drop_hdrlen, tlen, iptos, ti_locked); 1389 INP_INFO_UNLOCK_ASSERT(&V_tcbinfo); 1390 return; 1391 1392 dropwithreset: I believe you just wanted to spot the tcp_do_segment culprit here, but just in case the KTR traces provide any insight.. index cpu timestamp trace ------ --- ---------------- ----- 262 1 5346219888944675 KTRGRAPH group:"thread", id:"irq279: ix0:que 1 tid 100061", state:"running", attributes: prio:8 261 1 5346219888944167 KTRGRAPH group:"thread", id:"idle: cpu1 tid 100004", state:"idle", attributes: prio:255 260 1 5346219888942623 KTRGRAPH group:"load", id:"CPU 1 load", counter:1, attributes: none 259 1 5346219888942223 KTRGRAPH group:"thread", id:"idle: cpu1 tid 100004", point:"wokeup", attributes: linkedto:"irq279: ix0:que 1 tid 100061" 258 1 5346219888941935 KTRGRAPH group:"thread", id:"irq279: ix0:que 1 tid 100061", state:"runq add", attributes: prio:8, linkedto:"idle: cpu1 tid 100004" 257 4 5346219888867655 KTRGRAPH group:"thread", id:"idle: cpu4 tid 100007", state:"running", attributes: prio:255 256 4 5346219888866671 KTRGRAPH group:"load", id:"CPU 4 load", counter:0, attributes: none 255 4 5346219888866427 KTRGRAPH group:"thread", id:"EP tid 100276", state:"sleep", attributes: prio:152, wmesg:"kqread", lockname:"(null)" 254 4 5346219888866075 KTRGRAPH group:"thread", id:"EP tid 100276", point:"prio", attributes: prio:201, new prio:152, linkedto:"EP tid 100276" 253 3 5346219888839020 KTRGRAPH group:"thread", id:"idle: cpu3 tid 100006", state:"running", attributes: prio:255 252 4 5346219888838543 KTRGRAPH group:"thread", id:"EP tid 100276", state:"running", attributes: prio:152 251 3 5346219888837884 KTRGRAPH group:"load", id:"CPU 3 load", counter:0, attributes: none 250 3 5346219888837504 KTRGRAPH group:"thread", id:"dfetch tid 100281", state:"sleep", attributes: prio:139, wmesg:"sbwait", lockname:"(null)" 249 4 5346219888836847 KTRGRAPH group:"thread", id:"idle: cpu4 tid 100007", state:"idle", attributes: prio:255 248 3 5346219888834744 KTRGRAPH group:"load", id:"CPU 4 load", counter:1, attributes: none 247 3 5346219888833740 KTRGRAPH group:"thread", id:"dfetch tid 100281", point:"wokeup", attributes: linkedto:"EP tid 100276" 246 3 5346219888833532 KTRGRAPH group:"thread", id:"EP tid 100276", state:"runq add", attributes: prio:152, linkedto:"dfetch tid 100281" 245 4 5346219888833383 KTRGRAPH group:"thread", id:"idle: cpu4 tid 100007", state:"running", attributes: prio:255 244 4 5346219888831951 KTRGRAPH group:"load", id:"CPU 4 load", counter:0, attributes: none 243 4 5346219888831427 KTRGRAPH group:"thread", id:"EP tid 100276", state:"sleep", attributes: prio:152, wmesg:"kqread", lockname:"(null)" 242 4 5346219888830775 KTRGRAPH group:"thread", id:"EP tid 100276", point:"prio", attributes: prio:201, new prio:152, linkedto:"EP tid 100276" 241 3 5346219888805468 KTRGRAPH group:"thread", id:"dfetch tid 100281", state:"running", attributes: prio:139 240 3 5346219888804072 KTRGRAPH group:"thread", id:"idle: cpu3 tid 100006", state:"idle", attributes: prio:255 239 4 5346219888802939 KTRGRAPH group:"load", id:"CPU 3 load", counter:1, attributes: none 238 4 5346219888802067 KTRGRAPH group:"thread", id:"EP tid 100276", point:"wokeup", attributes: linkedto:"dfetch tid 100281" 237 4 5346219888801835 KTRGRAPH group:"thread", id:"dfetch tid 100281", state:"runq add", attributes: prio:139, linkedto:"EP tid 100276" 236 2 5346219888779438 KTRGRAPH group:"thread", id:"idle: cpu2 tid 100005", state:"running", attributes: prio:255 235 2 5346219888778694 KTRGRAPH group:"load", id:"CPU 2 load", counter:0, attributes: none 234 2 5346219888778466 KTRGRAPH group:"thread", id:"dfetch tid 100283", state:"sleep", attributes: prio:123, wmesg:"sbwait", lockname:"(null)" 233 2 5346219888750994 KTRGRAPH group:"thread", id:"dfetch tid 100283", state:"running", attributes: prio:123 232 2 5346219888749690 KTRGRAPH group:"thread", id:"idle: cpu2 tid 100005", state:"idle", attributes: prio:255 231 4 5346219888747775 KTRGRAPH group:"load", id:"CPU 2 load", counter:1, attributes: none 230 4 5346219888746907 KTRGRAPH group:"thread", id:"EP tid 100276", point:"wokeup", attributes: linkedto:"dfetch tid 100283" 229 4 5346219888746683 KTRGRAPH group:"thread", id:"dfetch tid 100283", state:"runq add", attributes: prio:123, linkedto:"EP tid 100276" 228 3 5346219888722124 KTRGRAPH group:"thread", id:"idle: cpu3 tid 100006", state:"running", attributes: prio:255 227 3 5346219888721356 KTRGRAPH group:"load", id:"CPU 3 load", counter:0, attributes: none 226 3 5346219888721132 KTRGRAPH group:"thread", id:"dfetch tid 100281", state:"sleep", attributes: prio:139, wmesg:"sbwait", lockname:"(null)" 225 3 5346219888693496 KTRGRAPH group:"thread", id:"dfetch tid 100281", state:"running", attributes: prio:139 224 3 5346219888692108 KTRGRAPH group:"thread", id:"idle: cpu3 tid 100006", state:"idle", attributes: prio:255 223 4 5346219888690959 KTRGRAPH group:"load", id:"CPU 3 load", counter:1, attributes: none 222 4 5346219888690151 KTRGRAPH group:"thread", id:"EP tid 100276", point:"wokeup", attributes: linkedto:"dfetch tid 100281" 221 4 5346219888689835 KTRGRAPH group:"thread", id:"dfetch tid 100281", state:"runq add", attributes: prio:139, linkedto:"EP tid 100276" 220 3 5346219888664956 KTRGRAPH group:"thread", id:"idle: cpu3 tid 100006", state:"running", attributes: prio:255 219 3 5346219888664188 KTRGRAPH group:"load", id:"CPU 3 load", counter:0, attributes: none 218 3 5346219888663956 KTRGRAPH group:"thread", id:"dfetch tid 100281", state:"sleep", attributes: prio:139, wmesg:"sbwait", lockname:"(null)" 217 3 5346219888636448 KTRGRAPH group:"thread", id:"dfetch tid 100281", state:"running", attributes: prio:139 216 3 5346219888635052 KTRGRAPH group:"thread", id:"idle: cpu3 tid 100006", state:"idle", attributes: prio:255 215 4 5346219888634055 KTRGRAPH group:"load", id:"CPU 3 load", counter:1, attributes: none 214 4 5346219888633175 KTRGRAPH group:"thread", id:"EP tid 100276", point:"wokeup", attributes: linkedto:"dfetch tid 100281" 213 4 5346219888632887 KTRGRAPH group:"thread", id:"dfetch tid 100281", state:"runq add", attributes: prio:139, linkedto:"EP tid 100276" 212 2 5346219888605666 KTRGRAPH group:"thread", id:"idle: cpu2 tid 100005", state:"running", attributes: prio:255 211 2 5346219888604894 KTRGRAPH group:"load", id:"CPU 2 load", counter:0, attributes: none 210 2 5346219888604670 KTRGRAPH group:"thread", id:"dfetch tid 100283", state:"sleep", attributes: prio:123, wmesg:"sbwait", lockname:"(null)" 209 2 5346219888579382 KTRGRAPH group:"thread", id:"dfetch tid 100283", state:"running", attributes: prio:123 208 2 5346219888578102 KTRGRAPH group:"thread", id:"idle: cpu2 tid 100005", state:"idle", attributes: prio:255 207 4 5346219888576151 KTRGRAPH group:"load", id:"CPU 2 load", counter:1, attributes: none 206 4 5346219888575307 KTRGRAPH group:"thread", id:"EP tid 100276", point:"wokeup", attributes: linkedto:"dfetch tid 100283" 205 4 5346219888575075 KTRGRAPH group:"thread", id:"dfetch tid 100283", state:"runq add", attributes: prio:123, linkedto:"EP tid 100276" 204 3 5346219888547276 KTRGRAPH group:"thread", id:"idle: cpu3 tid 100006", state:"running", attributes: prio:255 203 3 5346219888546492 KTRGRAPH group:"load", id:"CPU 3 load", counter:0, attributes: none 202 3 5346219888546256 KTRGRAPH group:"thread", id:"dfetch tid 100281", state:"sleep", attributes: prio:139, wmesg:"sbwait", lockname:"(null)" 201 3 5346219888518516 KTRGRAPH group:"thread", id:"dfetch tid 100281", state:"running", attributes: prio:139 200 3 5346219888517144 KTRGRAPH group:"thread", id:"idle: cpu3 tid 100006", state:"idle", attributes: prio:255 199 4 5346219888515955 KTRGRAPH group:"load", id:"CPU 3 load", counter:1, attributes: none 198 4 5346219888515051 KTRGRAPH group:"thread", id:"EP tid 100276", point:"wokeup", attributes: linkedto:"dfetch tid 100281" 197 4 5346219888514763 KTRGRAPH group:"thread", id:"dfetch tid 100281", state:"runq add", attributes: prio:139, linkedto:"EP tid 100276" 196 3 5346219888471648 KTRGRAPH group:"thread", id:"idle: cpu3 tid 100006", state:"running", attributes: prio:255 195 3 5346219888470864 KTRGRAPH group:"load", id:"CPU 3 load", counter:0, attributes: none 194 3 5346219888470608 KTRGRAPH group:"thread", id:"dfetch tid 100281", state:"sleep", attributes: prio:139, wmesg:"sbwait", lockname:"(null)" 193 3 5346219888444416 KTRGRAPH group:"thread", id:"dfetch tid 100281", state:"running", attributes: prio:139 192 3 5346219888443180 KTRGRAPH group:"thread", id:"idle: cpu3 tid 100006", state:"idle", attributes: prio:255 191 4 5346219888442191 KTRGRAPH group:"load", id:"CPU 3 load", counter:1, attributes: none 190 4 5346219888441299 KTRGRAPH group:"thread", id:"EP tid 100276", point:"wokeup", attributes: linkedto:"dfetch tid 100281" 189 4 5346219888441051 KTRGRAPH group:"thread", id:"dfetch tid 100281", state:"runq add", attributes: prio:139, linkedto:"EP tid 100276" 188 2 5346219888412126 KTRGRAPH group:"thread", id:"idle: cpu2 tid 100005", state:"running", attributes: prio:255 187 2 5346219888411186 KTRGRAPH group:"load", id:"CPU 2 load", counter:0, attributes: none 186 2 5346219888410734 KTRGRAPH group:"thread", id:"dfetch tid 100283", state:"sleep", attributes: prio:123, wmesg:"sbwait", lockname:"(null)" 185 3 5346219888406268 KTRGRAPH group:"thread", id:"idle: cpu3 tid 100006", state:"running", attributes: prio:255 184 3 5346219888405416 KTRGRAPH group:"load", id:"CPU 3 load", counter:0, attributes: none 183 3 5346219888405132 KTRGRAPH group:"thread", id:"dfetch tid 100281", state:"sleep", attributes: prio:139, wmesg:"sbwait", lockname:"(null)" 182 2 5346219888383370 KTRGRAPH group:"thread", id:"dfetch tid 100283", state:"running", attributes: prio:123 181 2 5346219888382134 KTRGRAPH group:"thread", id:"idle: cpu2 tid 100005", state:"idle", attributes: prio:255 180 4 5346219888380347 KTRGRAPH group:"load", id:"CPU 2 load", counter:1, attributes: none 179 4 5346219888379675 KTRGRAPH group:"thread", id:"EP tid 100276", point:"wokeup", attributes: linkedto:"dfetch tid 100283" 178 4 5346219888379363 KTRGRAPH group:"thread", id:"dfetch tid 100283", state:"runq add", attributes: prio:123, linkedto:"EP tid 100276" 177 3 5346219888377836 KTRGRAPH group:"thread", id:"dfetch tid 100281", state:"running", attributes: prio:139 176 3 5346219888376464 KTRGRAPH group:"thread", id:"idle: cpu3 tid 100006", state:"idle", attributes: prio:255 175 4 5346219888375403 KTRGRAPH group:"load", id:"CPU 3 load", counter:1, attributes: none 174 4 5346219888374439 KTRGRAPH group:"thread", id:"EP tid 100276", point:"wokeup", attributes: linkedto:"dfetch tid 100281" 173 4 5346219888374215 KTRGRAPH group:"thread", id:"dfetch tid 100281", state:"runq add", attributes: prio:139, linkedto:"EP tid 100276" 172 3 5346219888322428 KTRGRAPH group:"thread", id:"idle: cpu3 tid 100006", state:"running", attributes: prio:255 171 3 5346219888321656 KTRGRAPH group:"load", id:"CPU 3 load", counter:0, attributes: none 170 3 5346219888321352 KTRGRAPH group:"thread", id:"dfetch tid 100281", state:"sleep", attributes: prio:139, wmesg:"sbwait", lockname:"(null)" 169 3 5346219888293052 KTRGRAPH group:"thread", id:"dfetch tid 100281", state:"running", attributes: prio:139 168 3 5346219888291828 KTRGRAPH group:"thread", id:"idle: cpu3 tid 100006", state:"idle", attributes: prio:255 167 4 5346219888290659 KTRGRAPH group:"load", id:"CPU 3 load", counter:1, attributes: none 166 4 5346219888289723 KTRGRAPH group:"thread", id:"EP tid 100276", point:"wokeup", attributes: linkedto:"dfetch tid 100281" 165 4 5346219888289491 KTRGRAPH group:"thread", id:"dfetch tid 100281", state:"runq add", attributes: prio:139, linkedto:"EP tid 100276" 164 3 5346219888238840 KTRGRAPH group:"thread", id:"idle: cpu3 tid 100006", state:"running", attributes: prio:255 163 3 5346219888237796 KTRGRAPH group:"load", id:"CPU 3 load", counter:0, attributes: none 162 3 5346219888237356 KTRGRAPH group:"thread", id:"dfetch tid 100281", state:"sleep", attributes: prio:139, wmesg:"sbwait", lockname:"(null)" 161 2 5346219888224558 KTRGRAPH group:"thread", id:"idle: cpu2 tid 100005", state:"running", attributes: prio:255 160 2 5346219888223782 KTRGRAPH group:"load", id:"CPU 2 load", counter:0, attributes: none 159 2 5346219888223538 KTRGRAPH group:"thread", id:"dfetch tid 100283", state:"sleep", attributes: prio:123, wmesg:"sbwait", lockname:"(null)" 158 2 5346219888197174 KTRGRAPH group:"thread", id:"dfetch tid 100283", state:"running", attributes: prio:123 157 2 5346219888195814 KTRGRAPH group:"thread", id:"idle: cpu2 tid 100005", state:"idle", attributes: prio:255 156 4 5346219888193983 KTRGRAPH group:"load", id:"CPU 2 load", counter:1, attributes: none 155 4 5346219888193331 KTRGRAPH group:"thread", id:"EP tid 100276", point:"wokeup", attributes: linkedto:"dfetch tid 100283" 154 4 5346219888193051 KTRGRAPH group:"thread", id:"dfetch tid 100283", state:"runq add", attributes: prio:123, linkedto:"EP tid 100276" 153 3 5346219888191528 KTRGRAPH group:"thread", id:"dfetch tid 100281", state:"running", attributes: prio:139 152 3 5346219888190324 KTRGRAPH group:"thread", id:"idle: cpu3 tid 100006", state:"idle", attributes: prio:255 151 4 5346219888189243 KTRGRAPH group:"load", id:"CPU 3 load", counter:1, attributes: none 150 4 5346219888188227 KTRGRAPH group:"thread", id:"EP tid 100276", point:"wokeup", attributes: linkedto:"dfetch tid 100281" 149 4 5346219888187943 KTRGRAPH group:"thread", id:"dfetch tid 100281", state:"runq add", attributes: prio:139, linkedto:"EP tid 100276" 148 3 5346219888117040 KTRGRAPH group:"thread", id:"idle: cpu3 tid 100006", state:"running", attributes: prio:255 147 3 5346219888116276 KTRGRAPH group:"load", id:"CPU 3 load", counter:0, attributes: none 146 3 5346219888115840 KTRGRAPH group:"thread", id:"dfetch tid 100281", state:"sleep", attributes: prio:139, wmesg:"sbwait", lockname:"(null)" 145 1 5346219888098159 KTRGRAPH group:"thread", id:"idle: cpu1 tid 100004", state:"running", attributes: prio:255 144 1 5346219888097579 KTRGRAPH group:"load", id:"CPU 1 load", counter:0, attributes: none 143 1 5346219888097171 KTRGRAPH group:"thread", id:"irq279: ix0:que 1 tid 100061", state:"iwait", attributes: prio:8, wmesg:"(null)", lockname:"(null)" 142 3 5346219888088152 KTRGRAPH group:"thread", id:"dfetch tid 100281", state:"running", attributes: prio:139 141 3 5346219888086860 KTRGRAPH group:"thread", id:"idle: cpu3 tid 100006", state:"idle", attributes: prio:255 140 4 5346219888084999 KTRGRAPH group:"load", id:"CPU 3 load", counter:1, attributes: none 139 4 5346219888084087 KTRGRAPH group:"thread", id:"EP tid 100276", point:"wokeup", attributes: linkedto:"dfetch tid 100281" 138 4 5346219888083843 KTRGRAPH group:"thread", id:"dfetch tid 100281", state:"runq add", attributes: prio:139, linkedto:"EP tid 100276" 137 5 5346219888072781 KTRGRAPH group:"thread", id:"idle: cpu5 tid 100008", state:"running", attributes: prio:255 136 5 5346219888072481 KTRGRAPH group:"load", id:"CPU 5 load", counter:0, attributes: none 135 5 5346219888072285 KTRGRAPH group:"thread", id:"ix0 que tid 100062", state:"sleep", attributes: prio:8, wmesg:"-", lockname:"(null)" 134 5 5346219888069689 KTRGRAPH group:"thread", id:"ix0 que tid 100062", state:"running", attributes: prio:8 133 5 5346219888068753 KTRGRAPH group:"thread", id:"idle: cpu5 tid 100008", state:"idle", attributes: prio:255 132 5 5346219888067957 KTRGRAPH group:"thread", id:"idle: cpu5 tid 100008", point:"statclock", attributes: prio:255, stathz:127 131 1 5346219888062719 KTRGRAPH group:"load", id:"CPU 5 load", counter:1, attributes: none 130 1 5346219888061083 KTRGRAPH group:"thread", id:"irq279: ix0:que 1 tid 100061", point:"wokeup", attributes: linkedto:"ix0 que tid 100062" 129 1 5346219888060811 KTRGRAPH group:"thread", id:"ix0 que tid 100062", state:"runq add", attributes: prio:8, linkedto:"irq279: ix0:que 1 tid 100061" 128 4 5346219888029723 KTRGRAPH group:"thread", id:"EP tid 100276", state:"running", attributes: prio:152 127 4 5346219888028295 KTRGRAPH group:"thread", id:"idle: cpu4 tid 100007", state:"idle", attributes: prio:255 126 1 5346219888026515 KTRGRAPH group:"load", id:"CPU 4 load", counter:1, attributes: none 125 1 5346219888025739 KTRGRAPH group:"thread", id:"irq279: ix0:que 1 tid 100061", point:"wokeup", attributes: linkedto:"EP tid 100276" 124 1 5346219888025603 KTRGRAPH group:"thread", id:"EP tid 100276", state:"runq add", attributes: prio:152, linkedto:"irq279: ix0:que 1 tid 100061" 123 1 5346219887987103 KTRGRAPH group:"thread", id:"irq279: ix0:que 1 tid 100061", state:"running", attributes: prio:8 122 1 5346219887986611 KTRGRAPH group:"thread", id:"idle: cpu1 tid 100004", state:"idle", attributes: prio:255 121 1 5346219887984967 KTRGRAPH group:"load", id:"CPU 1 load", counter:1, attributes: none 120 1 5346219887984507 KTRGRAPH group:"thread", id:"idle: cpu1 tid 100004", point:"wokeup", attributes: linkedto:"irq279: ix0:que 1 tid 100061" 119 1 5346219887984307 KTRGRAPH group:"thread", id:"irq279: ix0:que 1 tid 100061", state:"runq add", attributes: prio:8, linkedto:"idle: cpu1 tid 100004" 118 4 5346219887875887 KTRGRAPH group:"thread", id:"idle: cpu4 tid 100007", state:"running", attributes: prio:255 117 4 5346219887874835 KTRGRAPH group:"load", id:"CPU 4 load", counter:0, attributes: none 116 4 5346219887874551 KTRGRAPH group:"thread", id:"EP tid 100276", state:"sleep", attributes: prio:152, wmesg:"kqread", lockname:"(null)" 115 4 5346219887874139 KTRGRAPH group:"thread", id:"EP tid 100276", point:"prio", attributes: prio:201, new prio:152, linkedto:"EP tid 100276" 114 3 5346219887848752 KTRGRAPH group:"thread", id:"idle: cpu3 tid 100006", state:"running", attributes: prio:255 113 4 5346219887847859 KTRGRAPH group:"thread", id:"EP tid 100276", state:"running", attributes: prio:152 112 3 5346219887847580 KTRGRAPH group:"load", id:"CPU 3 load", counter:0, attributes: none 111 3 5346219887847228 KTRGRAPH group:"thread", id:"dfetch tid 100281", state:"sleep", attributes: prio:139, wmesg:"sbwait", lockname:"(null)" 110 4 5346219887846167 KTRGRAPH group:"thread", id:"idle: cpu4 tid 100007", state:"idle", attributes: prio:255 109 3 5346219887844428 KTRGRAPH group:"load", id:"CPU 4 load", counter:1, attributes: none 108 3 5346219887843660 KTRGRAPH group:"thread", id:"dfetch tid 100281", point:"wokeup", attributes: linkedto:"EP tid 100276" 107 3 5346219887843448 KTRGRAPH group:"thread", id:"EP tid 100276", state:"runq add", attributes: prio:152, linkedto:"dfetch tid 100281" 106 4 5346219887823135 KTRGRAPH group:"thread", id:"idle: cpu4 tid 100007", state:"running", attributes: prio:255 105 4 5346219887821983 KTRGRAPH group:"load", id:"CPU 4 load", counter:0, attributes: none 104 4 5346219887821675 KTRGRAPH group:"thread", id:"EP tid 100276", state:"sleep", attributes: prio:152, wmesg:"kqread", lockname:"(null)" 103 4 5346219887821231 KTRGRAPH group:"thread", id:"EP tid 100276", point:"prio", attributes: prio:201, new prio:152, linkedto:"EP tid 100276" 102 3 5346219887817840 KTRGRAPH group:"thread", id:"dfetch tid 100281", state:"running", attributes: prio:139 101 3 5346219887816548 KTRGRAPH group:"thread", id:"idle: cpu3 tid 100006", state:"idle", attributes: prio:255 100 4 5346219887815395 KTRGRAPH group:"load", id:"CPU 3 load", counter:1, attributes: none 99 4 5346219887814459 KTRGRAPH group:"thread", id:"EP tid 100276", point:"wokeup", attributes: linkedto:"dfetch tid 100281" 98 4 5346219887814199 KTRGRAPH group:"thread", id:"dfetch tid 100281", state:"runq add", attributes: prio:139, linkedto:"EP tid 100276" 97 3 5346219887757636 KTRGRAPH group:"thread", id:"idle: cpu3 tid 100006", state:"running", attributes: prio:255 96 4 5346219887757263 KTRGRAPH group:"thread", id:"EP tid 100276", state:"running", attributes: prio:152 95 3 5346219887756492 KTRGRAPH group:"load", id:"CPU 3 load", counter:0, attributes: none 94 3 5346219887756104 KTRGRAPH group:"thread", id:"dfetch tid 100281", state:"sleep", attributes: prio:139, wmesg:"sbwait", lockname:"(null)" 93 4 5346219887755543 KTRGRAPH group:"thread", id:"idle: cpu4 tid 100007", state:"idle", attributes: prio:255 92 3 5346219887753420 KTRGRAPH group:"load", id:"CPU 4 load", counter:1, attributes: none 91 3 5346219887752476 KTRGRAPH group:"thread", id:"dfetch tid 100281", point:"wokeup", attributes: linkedto:"EP tid 100276" 90 3 5346219887752252 KTRGRAPH group:"thread", id:"EP tid 100276", state:"runq add", attributes: prio:152, linkedto:"dfetch tid 100281" 89 4 5346219887752095 KTRGRAPH group:"thread", id:"idle: cpu4 tid 100007", state:"running", attributes: prio:255 88 4 5346219887750663 KTRGRAPH group:"load", id:"CPU 4 load", counter:0, attributes: none 87 4 5346219887750331 KTRGRAPH group:"thread", id:"EP tid 100276", state:"sleep", attributes: prio:152, wmesg:"kqread", lockname:"(null)" 86 4 5346219887749791 KTRGRAPH group:"thread", id:"EP tid 100276", point:"prio", attributes: prio:201, new prio:152, linkedto:"EP tid 100276" 85 3 5346219887728324 KTRGRAPH group:"thread", id:"dfetch tid 100281", state:"running", attributes: prio:139 84 3 5346219887727048 KTRGRAPH group:"thread", id:"idle: cpu3 tid 100006", state:"idle", attributes: prio:255 83 4 5346219887726095 KTRGRAPH group:"load", id:"CPU 3 load", counter:1, attributes: none 82 4 5346219887725167 KTRGRAPH group:"thread", id:"EP tid 100276", point:"wokeup", attributes: linkedto:"dfetch tid 100281" 81 4 5346219887724943 KTRGRAPH group:"thread", id:"dfetch tid 100281", state:"runq add", attributes: prio:139, linkedto:"EP tid 100276" 80 3 5346219887706048 KTRGRAPH group:"thread", id:"idle: cpu3 tid 100006", state:"running", attributes: prio:255 79 3 5346219887705260 KTRGRAPH group:"load", id:"CPU 3 load", counter:0, attributes: none 78 3 5346219887705012 KTRGRAPH group:"thread", id:"dfetch tid 100281", state:"sleep", attributes: prio:139, wmesg:"sbwait", lockname:"(null)" 77 3 5346219887677908 KTRGRAPH group:"thread", id:"dfetch tid 100281", state:"running", attributes: prio:139 76 3 5346219887676408 KTRGRAPH group:"thread", id:"idle: cpu3 tid 100006", state:"idle", attributes: prio:255 75 4 5346219887675275 KTRGRAPH group:"load", id:"CPU 3 load", counter:1, attributes: none 74 4 5346219887674339 KTRGRAPH group:"thread", id:"EP tid 100276", point:"wokeup", attributes: linkedto:"dfetch tid 100281" 73 4 5346219887674067 KTRGRAPH group:"thread", id:"dfetch tid 100281", state:"runq add", attributes: prio:139, linkedto:"EP tid 100276" 72 3 5346219887643688 KTRGRAPH group:"thread", id:"idle: cpu3 tid 100006", state:"running", attributes: prio:255 71 3 5346219887642916 KTRGRAPH group:"load", id:"CPU 3 load", counter:0, attributes: none 70 3 5346219887642648 KTRGRAPH group:"thread", id:"dfetch tid 100281", state:"sleep", attributes: prio:139, wmesg:"sbwait", lockname:"(null)" 69 3 5346219887615124 KTRGRAPH group:"thread", id:"dfetch tid 100281", state:"running", attributes: prio:139 68 3 5346219887613600 KTRGRAPH group:"thread", id:"idle: cpu3 tid 100006", state:"idle", attributes: prio:255 67 4 5346219887612439 KTRGRAPH group:"load", id:"CPU 3 load", counter:1, attributes: none 66 4 5346219887611651 KTRGRAPH group:"thread", id:"EP tid 100276", point:"wokeup", attributes: linkedto:"dfetch tid 100281" 65 4 5346219887611375 KTRGRAPH group:"thread", id:"dfetch tid 100281", state:"runq add", attributes: prio:139, linkedto:"EP tid 100276" 64 3 5346219887606948 KTRGRAPH group:"thread", id:"idle: cpu3 tid 100006", state:"running", attributes: prio:255 63 3 5346219887606148 KTRGRAPH group:"load", id:"CPU 3 load", counter:0, attributes: none 62 3 5346219887605876 KTRGRAPH group:"thread", id:"dfetch tid 100281", state:"sleep", attributes: prio:139, wmesg:"sbwait", lockname:"(null)" 61 3 5346219887578020 KTRGRAPH group:"thread", id:"dfetch tid 100281", state:"running", attributes: prio:139 60 3 5346219887576736 KTRGRAPH group:"thread", id:"idle: cpu3 tid 100006", state:"idle", attributes: prio:255 59 4 5346219887575719 KTRGRAPH group:"load", id:"CPU 3 load", counter:1, attributes: none 58 4 5346219887574663 KTRGRAPH group:"thread", id:"EP tid 100276", point:"wokeup", attributes: linkedto:"dfetch tid 100281" 57 4 5346219887574391 KTRGRAPH group:"thread", id:"dfetch tid 100281", state:"runq add", attributes: prio:139, linkedto:"EP tid 100276" 56 3 5346219887514636 KTRGRAPH group:"thread", id:"idle: cpu3 tid 100006", state:"running", attributes: prio:255 55 3 5346219887513536 KTRGRAPH group:"load", id:"CPU 3 load", counter:0, attributes: none 54 3 5346219887513152 KTRGRAPH group:"thread", id:"dfetch tid 100281", state:"sleep", attributes: prio:139, wmesg:"sbwait", lockname:"(null)" 53 4 5346219887493515 KTRGRAPH group:"thread", id:"EP tid 100276", state:"running", attributes: prio:152 52 4 5346219887491871 KTRGRAPH group:"thread", id:"idle: cpu4 tid 100007", state:"idle", attributes: prio:255 51 3 5346219887489976 KTRGRAPH group:"load", id:"CPU 4 load", counter:1, attributes: none 50 3 5346219887488968 KTRGRAPH group:"thread", id:"dfetch tid 100281", point:"wokeup", attributes: linkedto:"EP tid 100276" 49 3 5346219887488688 KTRGRAPH group:"thread", id:"EP tid 100276", state:"runq add", attributes: prio:152, linkedto:"dfetch tid 100281" 48 4 5346219887488403 KTRGRAPH group:"thread", id:"idle: cpu4 tid 100007", state:"running", attributes: prio:255 47 4 5346219887486827 KTRGRAPH group:"load", id:"CPU 4 load", counter:0, attributes: none 46 4 5346219887486411 KTRGRAPH group:"thread", id:"EP tid 100276", state:"sleep", attributes: prio:152, wmesg:"kqread", lockname:"(null)" 45 4 5346219887485835 KTRGRAPH group:"thread", id:"EP tid 100276", point:"prio", attributes: prio:201, new prio:152, linkedto:"EP tid 100276" 44 3 5346219887440704 KTRGRAPH group:"thread", id:"dfetch tid 100281", state:"running", attributes: prio:139 43 3 5346219887439212 KTRGRAPH group:"thread", id:"idle: cpu3 tid 100006", state:"idle", attributes: prio:255 42 4 5346219887438063 KTRGRAPH group:"load", id:"CPU 3 load", counter:1, attributes: none 41 4 5346219887437079 KTRGRAPH group:"thread", id:"EP tid 100276", point:"wokeup", attributes: linkedto:"dfetch tid 100281" 40 4 5346219887436799 KTRGRAPH group:"thread", id:"dfetch tid 100281", state:"runq add", attributes: prio:139, linkedto:"EP tid 100276" 39 2 5346219887370146 KTRGRAPH group:"thread", id:"idle: cpu2 tid 100005", state:"running", attributes: prio:255 38 2 5346219887369366 KTRGRAPH group:"load", id:"CPU 2 load", counter:0, attributes: none 37 2 5346219887369102 KTRGRAPH group:"thread", id:"dfetch tid 100283", state:"sleep", attributes: prio:123, wmesg:"sbwait", lockname:"(null)" 36 2 5346219887340378 KTRGRAPH group:"thread", id:"dfetch tid 100283", state:"running", attributes: prio:123 35 2 5346219887338874 KTRGRAPH group:"thread", id:"idle: cpu2 tid 100005", state:"idle", attributes: prio:255 34 4 5346219887336903 KTRGRAPH group:"load", id:"CPU 2 load", counter:1, attributes: none 33 4 5346219887335995 KTRGRAPH group:"thread", id:"EP tid 100276", point:"wokeup", attributes: linkedto:"dfetch tid 100283" 32 4 5346219887335727 KTRGRAPH group:"thread", id:"dfetch tid 100283", state:"runq add", attributes: prio:123, linkedto:"EP tid 100276" 31 3 5346219887298672 KTRGRAPH group:"thread", id:"idle: cpu3 tid 100006", state:"running", attributes: prio:255 30 3 5346219887297652 KTRGRAPH group:"load", id:"CPU 3 load", counter:0, attributes: none 29 3 5346219887297304 KTRGRAPH group:"thread", id:"dfetch tid 100281", state:"sleep", attributes: prio:139, wmesg:"sbwait", lockname:"(null)" 28 3 5346219887229996 KTRGRAPH group:"thread", id:"dfetch tid 100281", state:"running", attributes: prio:139 27 3 5346219887228528 KTRGRAPH group:"thread", id:"idle: cpu3 tid 100006", state:"idle", attributes: prio:255 26 4 5346219887227515 KTRGRAPH group:"load", id:"CPU 3 load", counter:1, attributes: none 25 4 5346219887226503 KTRGRAPH group:"thread", id:"EP tid 100276", point:"wokeup", attributes: linkedto:"dfetch tid 100281" 24 4 5346219887226247 KTRGRAPH group:"thread", id:"dfetch tid 100281", state:"runq add", attributes: prio:139, linkedto:"EP tid 100276" 23 2 5346219887153494 KTRGRAPH group:"thread", id:"idle: cpu2 tid 100005", state:"running", attributes: prio:255 22 2 5346219887152702 KTRGRAPH group:"load", id:"CPU 2 load", counter:0, attributes: none 21 2 5346219887152226 KTRGRAPH group:"thread", id:"dfetch tid 100283", state:"sleep", attributes: prio:123, wmesg:"sbwait", lockname:"(null)" 20 1 5346219887147171 KTRGRAPH group:"thread", id:"idle: cpu1 tid 100004", state:"running", attributes: prio:255 19 1 5346219887146583 KTRGRAPH group:"load", id:"CPU 1 load", counter:0, attributes: none 18 1 5346219887146179 KTRGRAPH group:"thread", id:"irq279: ix0:que 1 tid 100061", state:"iwait", attributes: prio:8, wmesg:"(null)", lockname:"(null)" 17 2 5346219887125262 KTRGRAPH group:"thread", id:"dfetch tid 100283", state:"running", attributes: prio:123 16 2 5346219887124054 KTRGRAPH group:"thread", id:"idle: cpu2 tid 100005", state:"idle", attributes: prio:255 15 4 5346219887122139 KTRGRAPH group:"load", id:"CPU 2 load", counter:1, attributes: none 14 4 5346219887121247 KTRGRAPH group:"thread", id:"EP tid 100276", point:"wokeup", attributes: linkedto:"dfetch tid 100283" 13 4 5346219887121067 KTRGRAPH group:"thread", id:"dfetch tid 100283", state:"runq add", attributes: prio:123, linkedto:"EP tid 100276" 12 4 5346219887070771 KTRGRAPH group:"thread", id:"EP tid 100276", state:"running", attributes: prio:152 11 4 5346219887069227 KTRGRAPH group:"thread", id:"idle: cpu4 tid 100007", state:"idle", attributes: prio:255 10 1 5346219887067479 KTRGRAPH group:"load", id:"CPU 4 load", counter:1, attributes: none 9 1 5346219887066659 KTRGRAPH group:"thread", id:"irq279: ix0:que 1 tid 100061", point:"wokeup", attributes: linkedto:"EP tid 100276" 8 1 5346219887066495 KTRGRAPH group:"thread", id:"EP tid 100276", state:"runq add", attributes: prio:152, linkedto:"irq279: ix0:que 1 tid 100061" 7 1 5346219887029563 KTRGRAPH group:"thread", id:"irq279: ix0:que 1 tid 100061", state:"running", attributes: prio:8 6 1 5346219887029143 KTRGRAPH group:"thread", id:"idle: cpu1 tid 100004", state:"idle", attributes: prio:255 5 1 5346219887027871 KTRGRAPH group:"load", id:"CPU 1 load", counter:1, attributes: none 4 1 5346219887027399 KTRGRAPH group:"thread", id:"idle: cpu1 tid 100004", point:"wokeup", attributes: linkedto:"irq279: ix0:que 1 tid 100061" 3 1 5346219887027163 KTRGRAPH group:"thread", id:"irq279: ix0:que 1 tid 100061", state:"runq add", attributes: prio:8, linkedto:"idle: cpu1 tid 100004" 2 4 5346219886977607 KTRGRAPH group:"thread", id:"idle: cpu4 tid 100007", state:"running", attributes: prio:255 1 4 5346219886976619 KTRGRAPH group:"load", id:"CPU 4 load", counter:0, attributes: none 0 4 5346219886976335 KTRGRAPH group:"thread", id:"EP tid 100276", state:"sleep", attributes: prio:152, wmesg:"kqread", lockname:"(null)" Jason