trace priority changes

3 files changed, 71 insertions, 12 deletions

diff --git a/include/litmus/sched_trace.h b/include/litmus/sched_trace.h
index bc86f184be2c..c7652b1aef73 100644
--- a/include/litmus/sched_trace.h
+++ b/include/litmus/sched_trace.h
@@ -122,8 +122,8 @@ struct st_work_end_data {
 
 struct st_effective_priority_change_data {
         u64 when;
-        u16 inh_pid;
-        u8      __unused[6];
+        u32 inh_pid;
+        u32 prev_inh_pid;
 } __attribute__((packed));
 
 struct st_nv_interrupt_begin_data {
@@ -325,6 +325,7 @@ feather_callback void do_sched_trace_lock(unsigned long id,
 #define trace_litmus_task_block(t)
 #define trace_litmus_task_resume(t)
 #define trace_litmus_sys_release(start)
+#define trace_litmus_eff_prio_change(t, p)
 
 #endif
 
@@ -417,10 +418,12 @@ feather_callback void do_sched_trace_lock(unsigned long id,
 #define sched_trace_work_end(t, e, flushed) \
         SCHED_TRACE3(SCHED_TRACE_BASE_ID + 16, do_sched_trace_work_end, t, e, flushed)
 
-
-#define sched_trace_eff_prio_change(t, inh) \
-        SCHED_TRACE2(SCHED_TRACE_BASE_ID + 17, do_sched_trace_eff_prio_change, t, inh)
-
+#define sched_trace_eff_prio_change(t, p)                               \
+        do {                                                                                            \
+                SCHED_TRACE2(SCHED_TRACE_BASE_ID + 17,                  \
+                        do_sched_trace_eff_prio_change, t, p);          \
+                trace_litmus_eff_prio_change(t, p);                             \
+        } while (0)
 
 #define sched_trace_nv_interrupt_begin(d) \
         SCHED_TRACE(SCHED_TRACE_BASE_ID + 18, do_sched_trace_nv_interrupt_begin, d)
@@ -434,7 +437,6 @@ feather_callback void do_sched_trace_lock(unsigned long id,
 #define sched_trace_lock(t, lock_id, acquired) \
         SCHED_TRACE3(SCHED_TRACE_BASE_ID + 21, do_sched_trace_lock, t, lock_id, acquired)
 
-
 #define sched_trace_quantum_boundary() /* NOT IMPLEMENTED */
 
 #endif /* __KERNEL__ */
diff --git a/include/trace/events/litmus.h b/include/trace/events/litmus.h
index 0fffcee02be0..a444bbe40a2e 100644
--- a/include/trace/events/litmus.h
+++ b/include/trace/events/litmus.h
@@ -142,6 +142,8 @@ TRACE_EVENT(litmus_task_completion,
                 __field( unsigned int,  job     )
                 __field( lt_t,          when    )
                 __field( unsigned long, forced  )
+                __field( unsigned long, backlog )
+                __field( unsigned long, was_backlog_job)
         ),
 
         TP_fast_assign(
@@ -149,11 +151,15 @@ TRACE_EVENT(litmus_task_completion,
                 __entry->job    = t ? t->rt_param.job_params.job_no : 0;
                 __entry->when   = litmus_clock();
                 __entry->forced = forced;
+                __entry->backlog = t ? t->rt_param.job_params.backlog : 0;
+                __entry->was_backlog_job = t ? t->rt_param.job_params.is_backlogged_job : 0;
         ),
 
-        TP_printk("completed(job(%u, %u)): %Lu (forced: %lu)\n",
+        TP_printk("completed(job(%u, %u)): %Lu (forced: %lu) (was_bkj: %s) (bk_remain: %lu)\n",
                         __entry->pid, __entry->job,
-                        __entry->when, __entry->forced)
+                        __entry->when, __entry->forced,
+                        __entry->was_backlog_job ? "yes" : "no",
+                        __entry->backlog)
 );
 
 /*
@@ -168,14 +174,26 @@ TRACE_EVENT(litmus_task_block,
         TP_STRUCT__entry(
                 __field( pid_t,         pid     )
                 __field( lt_t,          when    )
+                __field( int,           for_io  )
         ),
 
         TP_fast_assign(
                 __entry->pid    = t ? t->pid : 0;
                 __entry->when   = litmus_clock();
+                __entry->for_io = t ? 0
+#ifdef CONFIG_REALTIME_AUX_TASKS
+                                || (t->rt_param.has_aux_tasks && !t->rt_param.hide_from_aux_tasks)
+#endif
+#ifdef CONFIG_LITMUS_NVIDIA
+                                || (t->rt_param.held_gpus && !t->rt_param.->hide_from_gpu)
+#endif
+                                : 0;
         ),
 
-        TP_printk("(%u) blocks: %Lu\n", __entry->pid, __entry->when)
+        TP_printk("(%u) blocks (for I/O: %s): %Lu\n",
+                                        __entry->pid,
+                                        __entry->for_io ? "yes" : "no",
+                                        __entry->when)
 );
 
 /*
@@ -225,6 +243,45 @@ TRACE_EVENT(litmus_sys_release,
         TP_printk("SynRelease(%Lu) at %Lu\n", __entry->rel, __entry->when)
 );
 
+TRACE_EVENT(litmus_eff_prio_change,
+
+        TP_PROTO(struct task_struct* t, struct task_struct* p),
+
+        TP_ARGS(t, p),
+
+        TP_STRUCT__entry(
+                __field( lt_t, when)
+                __field( pid_t, pid     )
+                __field( lt_t, deadline )
+                __field( pid_t, inh_pid )
+                __field( lt_t, inh_deadline )
+                __field( pid_t, prev_inh_pid )
+                __field( lt_t, prev_inh_deadline )
+        ),
+
+        TP_fast_assign(
+                __entry->when = litmus_clock();
+                __entry->pid = t ? t->pid : 0;
+                __entry->deadline = t ? t->rt_param.job_params.deadline : 0;
+                __entry->inh_pid = p ? p->pid : 0;
+                __entry->inh_deadline = p ? p->rt_param.job_params.deadline : 0;
+                __entry->prev_inh_pid = (t && t->rt_param.inh_task) ?
+                        t->rt_param.inh_task->pid : 0;
+                __entry->prev_inh_deadline = (t && t->rt_param.inh_task) ?
+                        t->rt_param.inh_task->rt_param.job_params.deadline : 0;
+        ),
+
+        TP_printk("Priority Change at %Lu: "
+                "%d @ %Lu (eff: %d @ %Lu) -> %d @ %Lu (prio %s)\n",
+                __entry->when,
+                __entry->pid, __entry->deadline,
+                __entry->prev_inh_pid, __entry->prev_inh_deadline,
+                __entry->inh_pid, __entry->inh_deadline,
+                (__entry->inh_pid) ?
+                        (__entry->inh_deadline <= (__entry->prev_inh_pid ? __entry->prev_inh_deadline : __entry->deadline)) ?
+                                "INCREASE" : "DECREASE" : "DECREASE")
+);
+
 #endif /* _SCHED_TASK_TRACEPOINT_H */
 
 /* Must stay outside the protection */
diff --git a/kernel/softirq.c b/kernel/softirq.c
index 9c20a9ec06b2..561d60ce1f65 100644
--- a/kernel/softirq.c
+++ b/kernel/softirq.c
@@ -31,7 +31,7 @@
 #include <asm/irq.h>
 
 #include <litmus/litmus.h>
-#include <litmus/sched_trace.h>
+//#include <litmus/sched_trace.h>
 
 #ifdef CONFIG_LITMUS_NVIDIA
 #include <litmus/nvidia_info.h>
@@ -472,7 +472,7 @@ static int __klmirqd_nv_tasklet_schedule(struct tasklet_struct *t,
                         klmirqd_th->pid,
                         litmus_clock());
 
-                sched_trace_tasklet_release(NULL, nvidia_device);
+//              sched_trace_tasklet_release(NULL, nvidia_device);
                 if(likely(klmirqd_func(t, klmirqd_th))) {
                         unlock_nvklmirqd_thread(nvidia_device, &flags);
                         return 1; /* success */