Date: Sat, 04 Mar 2017 09:13:46 -0800 From: John Baldwin <jhb@freebsd.org> To: freebsd-current@freebsd.org Cc: Andriy Gapon <avg@freebsd.org>, FreeBSD Current <freebsd-current@freebsd.org> Subject: Re: confusing KTR_SCHED traces Message-ID: <3582744.LcvQFR8qML@ralph.baldwin.cx> In-Reply-To: <e45fe46f-5431-dd3a-f688-9b34dad30d4f@FreeBSD.org> References: <e45fe46f-5431-dd3a-f688-9b34dad30d4f@FreeBSD.org>
next in thread | previous in thread | raw e-mail | index | archive | help
On Friday, February 17, 2017 08:48:57 PM Andriy Gapon wrote: > > First, an example, three consecutive entries for the same thread (from top to > bottom): > KTRGRAPH group:"thread", id:"zio_write_intr_3 tid 100260", state:"sleep", > attributes: prio:84, wmesg:"-", lockname:"(null)" > KTRGRAPH group:"thread", id:"zio_write_intr_3 tid 100260", state:"spinning", > attributes: lockname:"sched lock 1" > KTRGRAPH group:"thread", id:"zio_write_intr_3 tid 100260", state:"running", > attributes: none > > Any automatic analysis tool including schedgraph.py will assume that the thread > ends up in the running state. In reality, of course, the thread is in the > sleeping state. > The confusing trace is a result of logging the thread's intention to switch out > in mi_switch() before calling sched_switch(). In ULE's sched_switch() we > acquire the "TDQ_LOCK" which could be contested. In that case the thread spins > waiting for the lock to be released. This is reported as "spinning" and then > "running" states. > > I would like to fix that, but not sure how to do that best. > One idea is to move the mi_switch() trace closer to the cpu_switch() call > similarly to DTrace sched:cpu-off and sched:cpu-on probes. I think this is the right fix. -- John Baldwin
Want to link to this message? Use this URL: <https://mail-archive.FreeBSD.org/cgi/mid.cgi?3582744.LcvQFR8qML>