Date: Wed, 1 Mar 2017 17:17:24 +0800 From: Julian Elischer <julian@freebsd.org> To: freebsd-current@freebsd.org Subject: Re: confusing KTR_SCHED traces Message-ID: <b4a40505-36af-ed4e-7606-1fa8c7fe602b@freebsd.org> 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 18/2/17 2:48 am, 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 that is the way to fix it > > Any suggestions are welcome. > Thanks!
Want to link to this message? Use this URL: <https://mail-archive.FreeBSD.org/cgi/mid.cgi?b4a40505-36af-ed4e-7606-1fa8c7fe602b>