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;                 \
_______________________________________________
svn-src-head@freebsd.org mailing list
https://lists.freebsd.org/mailman/listinfo/svn-src-head
To unsubscribe, send any mail to "svn-src-head-unsubscr...@freebsd.org"

Reply via email to