Date: Fri, 17 Oct 2014 23:32:13 -0700 From: Jason Wolfe <nitroboost@gmail.com> To: John Baldwin <jhb@freebsd.org> Cc: Sean Bruno <sbruno@llnw.com>, freebsd-net@freebsd.org Subject: Re: ixgbe(4) spin lock held too long Message-ID: <CAAAm0r2Y359AtNyHrZ6J0TVLiws3ZTcfeYdfCimUZ8e1yHf5oA@mail.gmail.com> In-Reply-To: <201410161523.32415.jhb@freebsd.org> References: <1410203348.1343.1.camel@bruno> <3567780.Mf6fMnzmYG@ralph.baldwin.cx> <CAAAm0r01DqqNLUr0Mu15o2RLLdgnKntnFNKrw8TJut8XE7KNOw@mail.gmail.com> <201410161523.32415.jhb@freebsd.org>
next in thread | previous in thread | raw e-mail | index | archive | help
On Thu, Oct 16, 2014 at 12:23 PM, John Baldwin <jhb@freebsd.org> 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=<value optimized out>) at
/usr/src/sys/kern/kern_shutdown.c:759
#3 0xffffffff8084edba in tcp_timer_activate (tp=0x0,
timer_type=<value optimized out>, delta=0)
at /usr/src/sys/netinet/tcp_timer.c:695
#4 0xffffffff80841bad in tcp_do_segment (m=0xfffff80019898d00,
th=0xfffff80019898d82, so=0xfffff8026cafaae0,
tp=<value optimized out>, drop_hdrlen=<value optimized out>,
tlen=0, iptos=<value optimized out>, ti_locked=-2047)
at /usr/src/sys/netinet/tcp_input.c:2821
#5 0xffffffff8083f748 in tcp_input (m=<value optimized out>,
off0=<value optimized out>) 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=<value optimized
out>, source=<value optimized out>, m=0x0)
at /usr/src/sys/net/netisr.c:972
#8 0xffffffff807b1f06 in ether_demux (ifp=<value optimized out>,
m=0xfffff80019898d00) at /usr/src/sys/net/if_ethersubr.c:851
#9 0xffffffff807b2b99 in ether_nh_input (m=<value optimized out>) at
/usr/src/sys/net/if_ethersubr.c:646
#10 0xffffffff807b8a61 in netisr_dispatch_src (proto=<value optimized
out>, source=<value optimized out>, 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=<value optimized out>,
csum=<value optimized out>)
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=<value
optimized out>, ie=0xfffff8000e6fcb00)
at /usr/src/sys/kern/kern_intr.c:1263
---Type <return> to continue, or q <return> 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
<ithread_loop>, 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
Want to link to this message? Use this URL: <https://mail-archive.FreeBSD.org/cgi/mid.cgi?CAAAm0r2Y359AtNyHrZ6J0TVLiws3ZTcfeYdfCimUZ8e1yHf5oA>