add another two kinds of timing mechanisms for LKET, i.e. get_cycles() and

sched_clock()

8 files changed, 272 insertions, 20 deletions

diff --git a/runtime/ChangeLog b/runtime/ChangeLog
index a1f6d869..d830d1a7 100644
--- a/runtime/ChangeLog
+++ b/runtime/ChangeLog
@@ -1,3 +1,10 @@
+2006-08-29  Li Guanglei <guanglei@cn.ibm.com>
+
+	From Gui Jian <guijian@cn.ibm.com> 
+	* lket/b2a/lket_b2a.c, lket/b2a/lket_b2a.h:
+	add the support to get_cycles() and sched_clock() timing
+	mechanism for LKET.
+
 2006-08-14  Will Cohen  <wcohen@redhat.com>
 
 	PR 3037
diff --git a/runtime/lket/b2a/lket_b2a.c b/runtime/lket/b2a/lket_b2a.c
index 98c0b9de..352880f5 100644
--- a/runtime/lket/b2a/lket_b2a.c
+++ b/runtime/lket/b2a/lket_b2a.c
@@ -18,6 +18,21 @@
 #include <string.h>
 #include "lket_b2a.h"
 
+#define TIMING_GETCYCLES       0x01
+#define TIMING_GETTIMEOFDAY    0x02
+#define TIMING_SCHEDCLOCK      0x03
+
+typedef struct _cpufreq_info {
+	long		timebase;
+	long long	last_cycles;
+	long long	last_time;
+} cpufreq_info;
+
+#define MAX_CPUS		256
+cpufreq_info cpufreq[MAX_CPUS];
+
+static long timing_method = TIMING_GETTIMEOFDAY;
+
 static long long start_timestamp;
 
 /* Balanced binary search tree to store the 
@@ -98,17 +113,23 @@ int main(int argc, char *argv[])
 		}
 	}
 
+	// initialize the start cycles
+	if(timing_method == TIMING_GETCYCLES) {
+		for(i=0; i<MAX_CPUS; i++) {
+			cpufreq[i].last_cycles = start_timestamp;
+			cpufreq[i].last_time   = 0;
+		}
+	}
+
 	// main loop of parsing & merging
 	min = start_timestamp;
 	do {
 		// j is the next
 		if(min) {
-
 			if(HDR_GroupID(&hdrs[j])==_GROUP_REGEVT)  {
 				register_events(HDR_HookID(&hdrs[j]), infps[j], 
 					hdrs[j].sys_size);
 			} else  {
-
 				print_pkt_header(outfp, &hdrs[j]);
 
 				if(HDR_GroupID(&hdrs[j])==_GROUP_PROCESS &&
@@ -118,6 +139,22 @@ int main(int argc, char *argv[])
 					register_appname(j, infps[j], &hdrs[j]);
 				}
 
+				if(HDR_GroupID(&hdrs[j])==_GROUP_CPUFREQ
+					&& HDR_HookID(&hdrs[j])==_HOOKID_SWITCH_CPUFREQ
+					&& timing_method == TIMING_GETCYCLES) 
+				{
+					int64_t new_timebase;
+					fread(&new_timebase, sizeof(new_timebase), 1, infps[j]);
+
+					cpufreq[HDR_CpuID(&hdrs[j])].last_time += (hdrs[j].microsecond 
+						- cpufreq[HDR_CpuID(&hdrs[j])].last_cycles)
+						/ cpufreq[HDR_CpuID(&hdrs[j])].timebase;
+					cpufreq[j].last_cycles = hdrs[j].microsecond;
+					cpufreq[HDR_CpuID(&hdrs[j])].timebase = new_timebase;
+
+					fseek(infps[j], SEEK_CUR, -sizeof(new_timebase));
+				}
+
 				ascii_print(hdrs[j], infps[j], outfp, EVT_SYS);
 				if(hdrs[j].total_size != hdrs[j].sys_size)
 					ascii_print(hdrs[j], infps[j], outfp, EVT_USER);
@@ -234,7 +271,7 @@ int skip_sequence_id(FILE *fp)
  */
 void find_init_header(FILE **infps, const int total_infiles, FILE *outfp)
 {
-	int 	 i, j;
+	int 	 i, j, k;
 	int32_t magic;
 
 	/* information from lket_init_header */
@@ -242,7 +279,9 @@ void find_init_header(FILE **infps, const int total_infiles, FILE *outfp)
 	int8_t ver_major;
 	int8_t ver_minor;
 	int8_t big_endian;
+	int8_t timing_field; 
 	int8_t bits_width;
+	int32_t init_timebase;
 
 	if(total_infiles <= 0 )
 		return;
@@ -269,9 +308,31 @@ void find_init_header(FILE **infps, const int total_infiles, FILE *outfp)
 			if(fread(&big_endian, 1, sizeof(big_endian), infps[i]) < sizeof(big_endian))
 				break;
 			fprintf(outfp, "Big endian:\t%s\n", big_endian ? "YES":"NO");
+			if(fread(&timing_field, 1, sizeof(timing_field), infps[i]) < sizeof(timing_field))
+				break;
+			timing_method = timing_field;
+			fprintf(outfp, "Timing method:\t");
+			switch(timing_method) {
+				case TIMING_GETCYCLES: 
+					fprintf(outfp, "get_cycles()\n"); break;
+				case TIMING_GETTIMEOFDAY:
+					fprintf(outfp, "do_gettimeofday()\n"); break;
+				case TIMING_SCHEDCLOCK:
+					fprintf(outfp, "sched_clock()\n"); break;
+				default:
+					fprintf(outfp, "Unsupported timging method\n");
+			}
 			if(fread(&bits_width, 1, sizeof(bits_width), infps[i]) < sizeof(bits_width))
 				break;
 			fprintf(outfp, "Bits width:\t%d\n", bits_width);
+			if(fread(&init_timebase, 1, sizeof(init_timebase), infps[i]) < sizeof(init_timebase))
+				break;
+			fprintf(outfp, "Initial CPU timebase:\t%d (cycles per microsecond)\n", 
+					init_timebase);
+			if(timing_method == TIMING_GETCYCLES) {
+				for(k = 0; k < MAX_CPUS; k++)
+					cpufreq[k].timebase = init_timebase;
+			}
 			// skip the null terminater
 			fseek(infps[i], 1LL, SEEK_CUR);
 			break;
@@ -308,11 +369,22 @@ bad:
  */
 void print_pkt_header(FILE *fp, lket_pkt_header *phdr)
 {
+	long long usecs;
+	int sec, usec;
+
 	if(!fp || !phdr)
 		return;
-	long long usecs = phdr->microsecond - start_timestamp;
-	int sec = usecs/1000000;
-	int usec = usecs%1000000;
+
+	if(timing_method == TIMING_GETCYCLES)
+		usecs = (phdr->microsecond - cpufreq[HDR_CpuID(phdr)].last_cycles)
+			/ cpufreq[HDR_CpuID(phdr)].timebase + cpufreq[HDR_CpuID(phdr)].last_time;
+	else if(timing_method == TIMING_SCHEDCLOCK)
+		usecs = (phdr->microsecond - start_timestamp) / 1000;
+	else
+		usecs = phdr->microsecond - start_timestamp;
+	
+	sec = usecs/1000000;
+	usec = usecs%1000000;
 	
 	fprintf(fp, "\n%d.%d APPNAME: %s PID:%d CPU:%d HOOKGRP:%d HOOKID:%d -- ",
 		sec, usec,
diff --git a/runtime/lket/b2a/lket_b2a.h b/runtime/lket/b2a/lket_b2a.h
index d9cd4a26..10d26dff 100644
--- a/runtime/lket/b2a/lket_b2a.h
+++ b/runtime/lket/b2a/lket_b2a.h
@@ -31,6 +31,7 @@ int _GROUP_PAGEFAULT = 7;
 int _GROUP_NETDEV = 8;
 int _GROUP_IOSYSCALL = 9;
 int _GROUP_AIO = 10;
+int _GROUP_CPUFREQ = 15;
 
 /* hookIDs defined inside each group */
 int _HOOKID_REGSYSEVT = 1;
@@ -121,6 +122,9 @@ int _HOOKID_AIO_IO_DESTROY_RETURN = 10;
 int _HOOKID_AIO_IO_CANCEL_ENTRY = 11;
 int _HOOKID_AIO_IO_CANCEL_RETURN = 12;
 
+int _HOOKID_INIT_CPUFREQ = 1;
+int _HOOKID_SWITCH_CPUFREQ = 2;
+
 typedef struct _lket_pkt_header {
 	int16_t	total_size;
 	int16_t	sys_size;
diff --git a/tapset/LKET/Changelog b/tapset/LKET/Changelog
index 8f146973..e569bce5 100644
--- a/tapset/LKET/Changelog
+++ b/tapset/LKET/Changelog
@@ -1,3 +1,19 @@
+2006-08-29  Li Guanglei <guanglei@cn.ibm.com>
+	
+	From Gui Jian <guijian@cn.ibm.com>
+
+	New tapset to add another two kinds of timing methods,
+	i.e, get_cycles() and sched_clock().
+
+	* hookid_defs.stp: add CPUFREQ related definitions add 
+	lket_init_time/lket_kill_time to register/unregister 
+	cpufreq notifier
+	* lket_trace.stp: print timing_method and cpufreq in 
+	lket_init_header; use different timing methods in _lket_trace
+	* register_event.stp: register HOOKID_SWITCH_CPUFREQ event
+	* timestamp.stp: definitions of timing method related 
+	functions and variables
+	
 2006-08-25  Li Guanglei <guanglei@cn.ibm.com>
 	
 	* syscall.stp: add "probe never" to generate 
diff --git a/tapset/LKET/hookid_defs.stp b/tapset/LKET/hookid_defs.stp
index efcf6489..d3c09db7 100755
--- a/tapset/LKET/hookid_defs.stp
+++ b/tapset/LKET/hookid_defs.stp
@@ -130,8 +130,13 @@ global
 	HOOKID_SIGNAL_PROC_MASK_ENTRY,
 	HOOKID_SIGNAL_PROC_MASK_RETURN,
 
-	HOOKID_SIGNAL_FLUSH_ENTRY
-	
+	HOOKID_SIGNAL_FLUSH_ENTRY,
+
+	/* CPU Frequency */
+	GROUP_CPUFREQ,
+
+	HOOKID_SWITCH_CPUFREQ
+
 %{
 /* used in embedded c codes */
 
@@ -147,6 +152,7 @@ int _GROUP_NETDEV = 8;
 int _GROUP_IOSYSCALL = 9;
 int _GROUP_AIO = 10;
 int _GROUP_SIGNAL = 11;
+int _GROUP_CPUFREQ = 15;
 
 /* hookIDs defined inside each group */
 int _HOOKID_REGSYSEVT = 1;
@@ -253,6 +259,8 @@ int _HOOKID_SIGNAL_PROC_MASK_ENTRY = 13;
 int _HOOKID_SIGNAL_PROC_MASK_RETURN = 14;
 int _HOOKID_SIGNAL_FLUSH_ENTRY = 15;
 
+int _HOOKID_SWITCH_CPUFREQ = 1;
+
 %}
 
 function hookid_init()
@@ -379,6 +387,10 @@ function hookid_init()
 	HOOKID_SIGNAL_PROC_MASK_ENTRY = 13
 	HOOKID_SIGNAL_PROC_MASK_RETURN = 14
 	HOOKID_SIGNAL_FLUSH_ENTRY = 15
+
+	GROUP_CPUFREQ = 15
+
+	HOOKID_SWITCH_CPUFREQ = 2
 }
 
 
@@ -386,7 +398,13 @@ probe begin
 {
 	hookid_init()
 	lket_trace_init()
+	lket_init_time()
 	register_sys_events()
 	write_events_desc()	
 	process_snapshot()
 }
+
+probe end
+{
+	lket_kill_time()
+}
diff --git a/tapset/LKET/lket_trace.stp b/tapset/LKET/lket_trace.stp
index 59a08ec0..5764892a 100755
--- a/tapset/LKET/lket_trace.stp
+++ b/tapset/LKET/lket_trace.stp
@@ -6,6 +6,8 @@
 // later version.
 
 %{
+#include <linux/cpufreq.h>
+
 #if defined(ASCII_TRACE)
 #ifndef _FMT_
 #define _FMT_ unsigned int
@@ -15,6 +17,28 @@
 #define _FMT_ int64_t
 #endif
 #endif
+
+#ifndef TIMING_GETCYCLES
+#define TIMING_GETCYCLES 0x01
+#endif
+#ifndef TIMING_GETTIMEOFDAY
+#define TIMING_GETTIMEOFDAY 0x02
+#endif
+#ifndef TIMING_SCHEDCLOCK
+#define TIMING_SCHEDCLOCK 0x03
+#endif
+
+extern int _GROUP_CPUFREQ;
+extern int _HOOKID_SWITCH_CPUFREQ;
+
+extern long timing_method;
+
+#ifndef _PFN_SCHEDCLOCK_TYPE
+#define _PFN_SCHEDCLOCK_TYPE
+typedef unsigned long long (* pfn_schedclock_type)(void);
+#endif
+
+extern pfn_schedclock_type pfn_schedclock;
 %}
 
 function lket_trace_header_init()
@@ -30,12 +54,12 @@ function lket_trace_header_init()
 #define BIG_ENDIAN             0x02
 #define BITS_WIDTH             64     /* 32-bit or 64-bit environment*/
 
-	_stp_printf("%4b%2n%1b%1b%1b%1b", (_FMT_)MAGIC_NUMBER,
+	_stp_printf("%4b%2n%1b%1b%1b%1b%1b%4b", (_FMT_)MAGIC_NUMBER,
 		(_FMT_)LKET_TRACE_VER_MAJOR, (_FMT_)LKET_TRACE_VER_MINOR, 
-		(_FMT_)BIG_ENDIAN, (_FMT_)BITS_WIDTH);
+		(_FMT_)BIG_ENDIAN, (_FMT_)timing_method, 
+		(_FMT_)BITS_WIDTH, (_FMT_)__stp_estimate_cpufreq());
 	_stp_print_flush();
 #endif
-
 %}
 
 function lket_trace_init() 
@@ -124,19 +148,38 @@ static inline int this_event_len(void)
 
 /* we use 2 bytes to store the length. */
 #define _lket_trace(GroupID, hookID, fmt, args...) do { \
-	struct timeval tv; \
-	do_gettimeofday (&tv); \
-        _stp_printf("%2b%2n%8b%8b"fmt, (_FMT_)0, \
-		(_FMT_)(tv.tv_sec*1000000LL + tv.tv_usec),\
-		(_FMT_)((int64_t)current->pid << 32 | (int32_t)GroupID << 24 |\
-		 (int32_t)hookID << 16 | (int16_t)current->thread_info->cpu << 8), args);\
+	if(timing_method == TIMING_GETCYCLES) { \
+        	_stp_printf("%2b%2n%8b%8b"fmt, (_FMT_)0, \
+			(_FMT_)get_cycles(), \
+			(_FMT_)((int64_t)current->pid << 32 | \
+				(int32_t)GroupID << 24 | (int32_t)hookID << 16 | \
+			       	(int16_t)current->thread_info->cpu << 8), \
+			args); \
+	} \
+	else if(timing_method == TIMING_GETTIMEOFDAY) { \
+		struct timeval tv; \
+		do_gettimeofday (&tv); \
+		_stp_printf("%2b%2n%8b%8b"fmt, (_FMT_)0, \
+			(_FMT_)(tv.tv_sec*1000000LL + tv.tv_usec), \
+			(_FMT_)((int64_t)current->pid << 32 | \
+				(int32_t)GroupID << 24 | (int32_t)hookID << 16 | \
+			       	(int16_t)current->thread_info->cpu << 8), \
+			args); \
+	} \
+	else { \
+		_stp_printf("%2b%2n%8b%8b"fmt, (_FMT_)0, \
+			(_FMT_)pfn_schedclock(), \
+			(_FMT_)((int64_t)current->pid << 32 | \
+				(int32_t)GroupID << 24 | (int32_t)hookID << 16 | \
+				(int16_t)current->thread_info->cpu << 8), \
+			args); \
+	} \
 } while(0)
-
 #endif
+
 #endif
 %}
 
-
 function update_record()
 %{
 #if !defined(ASCII_TRACE)
@@ -145,3 +188,26 @@ function update_record()
 	*(int16_t *)total_length = _stp_pbuf_len[cpu] - 4;
 #endif
 %}
+
+%{
+#ifdef CONFIG_CPU_FREQ
+static int __lket_time_cpufreq_callback(struct notifier_block *self,
+        unsigned long state, void *vfreqs)
+{
+	int cpu;
+	unsigned long flags;
+	struct cpufreq_freqs *freqs;
+	unsigned int freq_mhz;
+	stp_time_t *time;
+
+	switch (state) {
+        	case CPUFREQ_POSTCHANGE:
+        	case CPUFREQ_RESUMECHANGE:
+			_lket_trace(_GROUP_CPUFREQ, _HOOKID_SWITCH_CPUFREQ, 
+				"%8b", __stp_estimate_cpufreq());
+		break;
+	}
+	return NOTIFY_OK;
+}
+#endif
+%}
diff --git a/tapset/LKET/register_event.stp b/tapset/LKET/register_event.stp
index 322be40b..e743c2ca 100755
--- a/tapset/LKET/register_event.stp
+++ b/tapset/LKET/register_event.stp
@@ -317,7 +317,9 @@ function register_sys_events()
 
 	register_sys_event(GROUP_SIGNAL, HOOKID_SIGNAL_FLUSH_ENTRY,
 		"INT32", "pid")
-			
+
+	register_sys_event(GROUP_CPUFREQ, HOOKID_SWITCH_CPUFREQ,
+		"INT64", "cpufreq")		
 }
 
 
diff --git a/tapset/LKET/timestamp.stp b/tapset/LKET/timestamp.stp
new file mode 100755
index 00000000..471177a9
--- /dev/null
+++ b/tapset/LKET/timestamp.stp
@@ -0,0 +1,67 @@
+%{
+#ifndef TIMING_GETCYCLES
+#define TIMING_GETCYCLES 0x01
+#endif
+#ifndef TIMING_GETTIMEOFDAY
+#define TIMING_GETTIMEOFDAY 0x02
+#endif
+#ifndef TIMING_SCHEDCLOCK
+#define TIMING_SCHEDCLOCK 0x03
+#endif
+
+#define MAX_TIMING_METHOD TIMING_SCHEDCLOCK
+
+long timing_method = TIMING_GETTIMEOFDAY;
+
+#ifndef _PFN_SCHEDCLOCK_TYPE
+#define _PFN_SCHEDCLOCK_TYPE
+typedef unsigned long long (* pfn_schedclock_type)(void);
+#endif
+
+pfn_schedclock_type pfn_schedclock = NULL;
+%}
+
+%{
+#ifdef CONFIG_CPU_FREQ
+static int __lket_time_cpufreq_callback(struct notifier_block *self,
+		unsigned long state, void *vfreqs);
+
+struct notifier_block __lket_time_notifier = {
+	.notifier_call = __lket_time_cpufreq_callback,
+};
+
+#endif
+%}
+
+function set_timing_method(method:long)
+%{
+	if(THIS->method == TIMING_SCHEDCLOCK) {
+		pfn_schedclock = (pfn_schedclock_type)kallsyms_lookup_name("sched_clock");
+		if(!pfn_schedclock) {
+			_stp_warn("Failed to lookup specified timing method sched_clock()\n");
+			return;
+		}
+	}
+	if(THIS->method > 0 && THIS->method <= MAX_TIMING_METHOD)
+		timing_method = THIS->method;
+%}
+
+function lket_init_time:long()
+%{
+	int ret = 0;
+#ifdef CONFIG_CPU_FREQ
+	if(timing_method == TIMING_GETCYCLES)
+		ret = cpufreq_register_notifier(&__lket_time_notifier,
+			CPUFREQ_TRANSITION_NOTIFIER);
+#endif
+	THIS->__retvalue = ret;
+%}
+
+function lket_kill_time()
+%{
+#ifdef CONFIG_CPU_FREQ
+	if(timing_method == TIMING_GETCYCLES)
+		cpufreq_unregister_notifier(&__lket_time_notifier, 
+			CPUFREQ_TRANSITION_NOTIFIER);
+#endif
+%}