Feather-Trace: keep track of release latency

3 files changed, 32 insertions, 2 deletions

diff --git a/include/litmus/trace.h b/include/litmus/trace.h
index a725e8b583ba..e2926a08c2f4 100644
--- a/include/litmus/trace.h
+++ b/include/litmus/trace.h
@@ -28,7 +28,7 @@ feather_callback void save_timestamp(unsigned long event);
 feather_callback void save_timestamp_def(unsigned long event, unsigned long type);
 feather_callback void save_timestamp_task(unsigned long event, unsigned long t_ptr);
 feather_callback void save_timestamp_cpu(unsigned long event, unsigned long cpu);
-
+feather_callback void save_task_latency(unsigned long event, unsigned long when_ptr);
 
 #define TIMESTAMP(id) ft_event0(id, save_timestamp)
 
@@ -40,6 +40,9 @@ feather_callback void save_timestamp_cpu(unsigned long event, unsigned long cpu)
 #define CTIMESTAMP(id, cpu) \
         ft_event1(id, save_timestamp_cpu, (unsigned long) cpu)
 
+#define LTIMESTAMP(id, task) \
+        ft_event1(id, save_task_latency, (unsigned long) task)
+
 #else /* !CONFIG_SCHED_OVERHEAD_TRACE */
 
 #define TIMESTAMP(id)        /* no tracing */
@@ -50,6 +53,8 @@ feather_callback void save_timestamp_cpu(unsigned long event, unsigned long cpu)
 
 #define CTIMESTAMP(id, cpu)  /* no tracing */
 
+#define LTIMESTAMP(id, when_ptr) /* no tracing */
+
 #endif
 
 
@@ -61,6 +66,8 @@ feather_callback void save_timestamp_cpu(unsigned long event, unsigned long cpu)
  * always the next number after the start time event id.
  */
 
+
+
 #define TS_SCHED_START                  DTIMESTAMP(100, TSK_UNKNOWN) /* we only
                                                                       * care
                                                                       * about
@@ -102,5 +109,6 @@ feather_callback void save_timestamp_cpu(unsigned long event, unsigned long cpu)
 #define TS_SEND_RESCHED_START(c)        CTIMESTAMP(190, c)
 #define TS_SEND_RESCHED_END             DTIMESTAMP(191, TSK_UNKNOWN)
 
+#define TS_RELEASE_LATENCY(when)        LTIMESTAMP(208, &(when))
 
 #endif /* !_SYS_TRACE_H_ */
diff --git a/litmus/rt_domain.c b/litmus/rt_domain.c
index 81a5ac16f164..d405854cd39c 100644
--- a/litmus/rt_domain.c
+++ b/litmus/rt_domain.c
@@ -55,12 +55,14 @@ static enum hrtimer_restart on_release_timer(struct hrtimer *timer)
 {
         unsigned long flags;
         struct release_heap* rh;
+        rh = container_of(timer, struct release_heap, timer);
+
+        TS_RELEASE_LATENCY(rh->release_time);
 
         VTRACE("on_release_timer(0x%p) starts.\n", timer);
 
         TS_RELEASE_START;
 
-        rh = container_of(timer, struct release_heap, timer);
 
         raw_spin_lock_irqsave(&rh->dom->release_lock, flags);
         VTRACE("CB has the release_lock 0x%p\n", &rh->dom->release_lock);
diff --git a/litmus/trace.c b/litmus/trace.c
index 1e916aa406b9..f0eb2c706488 100644
--- a/litmus/trace.c
+++ b/litmus/trace.c
@@ -61,6 +61,26 @@ feather_callback void save_timestamp_cpu(unsigned long event,
         __save_timestamp_cpu(event, TSK_UNKNOWN, cpu);
 }
 
+feather_callback void save_task_latency(unsigned long event,
+                                        unsigned long when_ptr)
+{
+        lt_t now = litmus_clock();
+        lt_t *when = (lt_t*) when_ptr;
+        unsigned int seq_no;
+        int cpu = raw_smp_processor_id();
+        struct timestamp *ts;
+
+        seq_no = fetch_and_inc((int *) &ts_seq_no);
+        if (ft_buffer_start_write(trace_ts_buf, (void**)  &ts)) {
+                ts->event     = event;
+                ts->timestamp = now - *when;
+                ts->seq_no    = seq_no;
+                ts->cpu       = cpu;
+                ts->task_type = TSK_RT;
+                ft_buffer_finish_write(trace_ts_buf, ts);
+        }
+}
+
 /******************************************************************************/
 /*                        DEVICE FILE DRIVER                                  */
 /******************************************************************************/