Date: Thu, 23 Mar 2017 08:57:04 +0000 (UTC) From: Andriy Gapon <avg@FreeBSD.org> To: src-committers@freebsd.org, svn-src-all@freebsd.org, svn-src-head@freebsd.org Subject: svn commit: r315851 - in head/sys: kern sys Message-ID: <201703230857.v2N8v456011537@repo.freebsd.org>
next in thread | raw e-mail | index | archive | help
Author: avg Date: Thu Mar 23 08:57:04 2017 New Revision: 315851 URL: https://svnweb.freebsd.org/changeset/base/315851 Log: move thread switch tracing from mi_switch to sched_switch This is done so that the thread state changes during the switch are not confused with the thread state changes reported when the thread spins on a lock. Here is 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 The above trace could leave an impression that the final state of the thread was "running". After this change the sleep state will be reported after the "spinning" and "running" states reported for the sched lock. Reviewed by: jhb, markj MFC after: 1 week Sponsored by: Panzura Differential Revision: https://reviews.freebsd.org/D9961 Modified: head/sys/kern/kern_synch.c head/sys/kern/sched_4bsd.c head/sys/kern/sched_ule.c head/sys/sys/proc.h Modified: head/sys/kern/kern_synch.c ============================================================================== --- head/sys/kern/kern_synch.c Thu Mar 23 08:34:30 2017 (r315850) +++ head/sys/kern/kern_synch.c Thu Mar 23 08:57:04 2017 (r315851) @@ -66,13 +66,6 @@ __FBSDID("$FreeBSD$"); #include <machine/cpu.h> -#define KTDSTATE(td) \ - (((td)->td_inhibitors & TDI_SLEEPING) != 0 ? "sleep" : \ - ((td)->td_inhibitors & TDI_SUSPENDED) != 0 ? "suspended" : \ - ((td)->td_inhibitors & TDI_SWAPPED) != 0 ? "swapped" : \ - ((td)->td_inhibitors & TDI_LOCK) != 0 ? "blocked" : \ - ((td)->td_inhibitors & TDI_IWAIT) != 0 ? "iwait" : "yielding") - static void synch_setup(void *dummy); SYSINIT(synch_setup, SI_SUB_KICK_SCHEDULER, SI_ORDER_FIRST, synch_setup, NULL); @@ -437,20 +430,8 @@ mi_switch(int flags, struct thread *newt PCPU_SET(switchticks, ticks); CTR4(KTR_PROC, "mi_switch: old thread %ld (td_sched %p, pid %ld, %s)", td->td_tid, td_get_sched(td), td->td_proc->p_pid, td->td_name); -#if (KTR_COMPILE & KTR_SCHED) != 0 - if (TD_IS_IDLETHREAD(td)) - KTR_STATE1(KTR_SCHED, "thread", sched_tdname(td), "idle", - "prio:%d", td->td_priority); - else - KTR_STATE3(KTR_SCHED, "thread", sched_tdname(td), KTDSTATE(td), - "prio:%d", td->td_priority, "wmesg:\"%s\"", td->td_wmesg, - "lockname:\"%s\"", td->td_lockname); -#endif SDT_PROBE0(sched, , , preempt); sched_switch(td, newtd, flags); - KTR_STATE1(KTR_SCHED, "thread", sched_tdname(td), "running", - "prio:%d", td->td_priority); - CTR4(KTR_PROC, "mi_switch: new thread %ld (td_sched %p, pid %ld, %s)", td->td_tid, td_get_sched(td), td->td_proc->p_pid, td->td_name); Modified: head/sys/kern/sched_4bsd.c ============================================================================== --- head/sys/kern/sched_4bsd.c Thu Mar 23 08:34:30 2017 (r315850) +++ head/sys/kern/sched_4bsd.c Thu Mar 23 08:57:04 2017 (r315851) @@ -1013,6 +1013,16 @@ sched_switch(struct thread *td, struct t MPASS(newtd->td_lock == &sched_lock); } +#if (KTR_COMPILE & KTR_SCHED) != 0 + if (TD_IS_IDLETHREAD(td)) + KTR_STATE1(KTR_SCHED, "thread", sched_tdname(td), "idle", + "prio:%d", td->td_priority); + else + KTR_STATE3(KTR_SCHED, "thread", sched_tdname(td), KTDSTATE(td), + "prio:%d", td->td_priority, "wmesg:\"%s\"", td->td_wmesg, + "lockname:\"%s\"", td->td_lockname); +#endif + if (td != newtd) { #ifdef HWPMC_HOOKS if (PMC_PROC_IS_USING_PMCS(td->td_proc)) @@ -1061,6 +1071,9 @@ sched_switch(struct thread *td, struct t } else SDT_PROBE0(sched, , , remain__cpu); + KTR_STATE1(KTR_SCHED, "thread", sched_tdname(td), "running", + "prio:%d", td->td_priority); + #ifdef SMP if (td->td_flags & TDF_IDLETD) CPU_SET(PCPU_GET(cpuid), &idle_cpus_mask); Modified: head/sys/kern/sched_ule.c ============================================================================== --- head/sys/kern/sched_ule.c Thu Mar 23 08:34:30 2017 (r315850) +++ head/sys/kern/sched_ule.c Thu Mar 23 08:57:04 2017 (r315851) @@ -1938,6 +1938,17 @@ sched_switch(struct thread *td, struct t mtx = thread_lock_block(td); tdq_load_rem(tdq, td); } + +#if (KTR_COMPILE & KTR_SCHED) != 0 + if (TD_IS_IDLETHREAD(td)) + KTR_STATE1(KTR_SCHED, "thread", sched_tdname(td), "idle", + "prio:%d", td->td_priority); + else + KTR_STATE3(KTR_SCHED, "thread", sched_tdname(td), KTDSTATE(td), + "prio:%d", td->td_priority, "wmesg:\"%s\"", td->td_wmesg, + "lockname:\"%s\"", td->td_lockname); +#endif + /* * We enter here with the thread blocked and assigned to the * appropriate cpu run-queue or sleep-queue and with the current @@ -1988,6 +1999,10 @@ sched_switch(struct thread *td, struct t thread_unblock_switch(td, mtx); SDT_PROBE0(sched, , , remain__cpu); } + + KTR_STATE1(KTR_SCHED, "thread", sched_tdname(td), "running", + "prio:%d", td->td_priority); + /* * Assert that all went well and return. */ Modified: head/sys/sys/proc.h ============================================================================== --- head/sys/sys/proc.h Thu Mar 23 08:34:30 2017 (r315850) +++ head/sys/sys/proc.h Thu Mar 23 08:57:04 2017 (r315851) @@ -488,6 +488,12 @@ do { \ #define TD_ON_UPILOCK(td) ((td)->td_flags & TDF_UPIBLOCKED) #define TD_IS_IDLETHREAD(td) ((td)->td_flags & TDF_IDLETD) +#define KTDSTATE(td) \ + (((td)->td_inhibitors & TDI_SLEEPING) != 0 ? "sleep" : \ + ((td)->td_inhibitors & TDI_SUSPENDED) != 0 ? "suspended" : \ + ((td)->td_inhibitors & TDI_SWAPPED) != 0 ? "swapped" : \ + ((td)->td_inhibitors & TDI_LOCK) != 0 ? "blocked" : \ + ((td)->td_inhibitors & TDI_IWAIT) != 0 ? "iwait" : "yielding") #define TD_SET_INHIB(td, inhib) do { \ (td)->td_state = TDS_INHIBITED; \
Want to link to this message? Use this URL: <https://mail-archive.FreeBSD.org/cgi/mid.cgi?201703230857.v2N8v456011537>