confusing KTR_SCHED traces
avg at FreeBSD.org
Fri Feb 17 18:50:02 UTC 2017
First, an example, three consecutive entries for the same thread (from top to
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",
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
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
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.
Any suggestions are welcome.
More information about the freebsd-current