diff options
| -rw-r--r-- | runtime/ChangeLog | 7 | ||||
| -rw-r--r-- | runtime/lket/b2a/lket_b2a.c | 84 | ||||
| -rw-r--r-- | runtime/lket/b2a/lket_b2a.h | 4 | ||||
| -rw-r--r-- | tapset/LKET/Changelog | 16 | ||||
| -rwxr-xr-x | tapset/LKET/hookid_defs.stp | 22 | ||||
| -rwxr-xr-x | tapset/LKET/lket_trace.stp | 88 | ||||
| -rwxr-xr-x | tapset/LKET/register_event.stp | 4 | ||||
| -rwxr-xr-x | tapset/LKET/timestamp.stp | 67 |
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 +%} |