locking: trace system call entry/exit cost

5 files changed, 72 insertions, 1 deletions

diff --git a/include/litmus/litmus.h b/include/litmus/litmus.h
index 2112eecd1dc8..a3fd5dd269fc 100644
--- a/include/litmus/litmus.h
+++ b/include/litmus/litmus.h
@@ -129,6 +129,16 @@ void srp_ceiling_block(void);
 
 #define bheap2task(hn) ((struct task_struct*) hn->value)
 
+static inline struct control_page* get_control_page(struct task_struct *t)
+{
+        return tsk_rt(t)->ctrl_page;
+}
+
+static inline int has_control_page(struct task_struct* t)
+{
+        return tsk_rt(t)->ctrl_page != NULL;
+}
+
 #ifdef CONFIG_NP_SECTION
 
 static inline int is_kernel_np(struct task_struct *t)
diff --git a/include/litmus/rt_param.h b/include/litmus/rt_param.h
index e6288e8807f0..221edad83d77 100644
--- a/include/litmus/rt_param.h
+++ b/include/litmus/rt_param.h
@@ -63,6 +63,9 @@ struct control_page {
          * its non-preemptive section? */
         int delayed_preemption;
 
+        /* locking overhead tracing: time stamp prior to system call */
+        uint64_t ts_syscall_start; /* Feather-Trace cycles */
+
         /* to be extended */
 };
 
diff --git a/include/litmus/trace.h b/include/litmus/trace.h
index 05f487263f28..d641375bbb04 100644
--- a/include/litmus/trace.h
+++ b/include/litmus/trace.h
@@ -28,7 +28,8 @@ 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);
+feather_callback void save_timestamp_time(unsigned long event, unsigned long time_ptr);
 
 #define TIMESTAMP(id) ft_event0(id, save_timestamp)
 
@@ -40,6 +41,12 @@ 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)
+
+#define TIMESTAMP_TIME(id, time_ptr) \
+        ft_event1(id, save_timestamp_time, (unsigned long) time_ptr)
+
 #else /* !CONFIG_SCHED_OVERHEAD_TRACE */
 
 #define TIMESTAMP(id)        /* no tracing */
@@ -50,6 +57,10 @@ 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 */
+
+#define TIMESTAMP_TIME(id, time_ptr) /* no tracing */
+
 #endif
 
 
@@ -96,6 +107,13 @@ feather_callback void save_timestamp_cpu(unsigned long event, unsigned long cpu)
 #define TS_UNLOCK_START                 TIMESTAMP(172)
 #define TS_UNLOCK_END                   TIMESTAMP(173)
 
+#define TS_SYSCALL_IN_START(p)          TIMESTAMP_TIME(190, p)
+#define TS_SYSCALL_IN_END               TIMESTAMP(191)
+
+#define TS_SYSCALL_OUT_START            TIMESTAMP(200)
+#define TS_SYSCALL_OUT_END              TIMESTAMP(201)
+
+
 #define TS_SEND_RESCHED_START(c)        CTIMESTAMP(190, c)
 #define TS_SEND_RESCHED_END             DTIMESTAMP(191, TSK_UNKNOWN)
 
diff --git a/litmus/locking.c b/litmus/locking.c
index 728b56835cf7..cfbc1ba59217 100644
--- a/litmus/locking.c
+++ b/litmus/locking.c
@@ -1,3 +1,5 @@
+#include <linux/sched.h>
+#include <litmus/litmus.h>
 #include <litmus/fdso.h>
 
 #ifdef CONFIG_LITMUS_LOCKING
@@ -69,6 +71,11 @@ asmlinkage long sys_litmus_lock(int lock_od)
         struct od_table_entry* entry;
         struct litmus_lock* l;
 
+        if (has_control_page(current))
+                TS_SYSCALL_IN_START(&get_control_page(current)->ts_syscall_start);
+
+        TS_SYSCALL_IN_END;
+
         TS_LOCK_START;
 
         entry = get_entry_for_od(lock_od);
@@ -82,6 +89,8 @@ asmlinkage long sys_litmus_lock(int lock_od)
          * this into account when computing overheads. */
         TS_UNLOCK_END;
 
+        TS_SYSCALL_OUT_START;
+
         return err;
 }
 
@@ -91,6 +100,11 @@ asmlinkage long sys_litmus_unlock(int lock_od)
         struct od_table_entry* entry;
         struct litmus_lock* l;
 
+        if (has_control_page(current))
+                TS_SYSCALL_IN_START(&get_control_page(current)->ts_syscall_start);
+
+        TS_SYSCALL_IN_END;
+
         TS_UNLOCK_START;
 
         entry = get_entry_for_od(lock_od);
@@ -104,6 +118,8 @@ asmlinkage long sys_litmus_unlock(int lock_od)
          * account when computing overheads. */
         TS_UNLOCK_END;
 
+        TS_SYSCALL_OUT_START;
+
         return err;
 }
 
diff --git a/litmus/trace.c b/litmus/trace.c
index e7ea1c2ab3e4..23763c19fa6b 100644
--- a/litmus/trace.c
+++ b/litmus/trace.c
@@ -37,6 +37,30 @@ static inline void __save_timestamp(unsigned long event,
         __save_timestamp_cpu(event, type, raw_smp_processor_id());
 }
 
+static inline uint8_t task_type(struct task_struct* t)
+{
+        if (!t)
+                return TSK_UNKNOWN;
+        else
+                return is_realtime(t) ? TSK_RT : TSK_BE;
+}
+
+feather_callback void save_timestamp_time(unsigned long event, unsigned long ptr)
+{
+        uint64_t* time = (uint64_t*) ptr;
+        unsigned int seq_no;
+        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 = *time;
+                ts->seq_no    = seq_no;
+                ts->cpu       = raw_smp_processor_id();
+                ts->task_type = task_type(current);
+                ft_buffer_finish_write(trace_ts_buf, ts);
+        }
+}
+
 feather_callback void save_timestamp(unsigned long event)
 {
         __save_timestamp(event, TSK_UNKNOWN);