/*
- cc -I. -DKERNEL_PRIVATE -O -o latency latency.c
+ cc -I. -DPRIVATE -D__APPLE_PRIVATE -O -o latency latency.c -lncurses
*/
#include <mach/mach.h>
#include <libc.h>
#include <termios.h>
-#include <bsd/curses.h>
+#include <curses.h>
#include <sys/ioctl.h>
#ifndef KERNEL_PRIVATE
#include <mach/mach_types.h>
#include <mach/message.h>
#include <mach/mach_syscalls.h>
-#include <mach/clock.h>
#include <mach/clock_types.h>
+#include <mach/mach_time.h>
#include <libkern/OSTypes.h>
double divisor;
int gotSIGWINCH = 0;
int trace_enabled = 0;
+struct host_basic_info hi;
+
#define SAMPLE_SIZE 300000
} codes_tab[MAX_ENTRIES];
+#define NUMPARMS 23
+
struct th_info {
int thread;
int type;
int child_thread;
- int vfslookup;
int arg1;
double stime;
- char pathname[32];
+ long *pathptr;
+ long pathname[NUMPARMS + 1];
};
#define MAX_THREADS 512
#define DBG_FUNC_ALL (DBG_FUNC_START | DBG_FUNC_END)
#define DBG_FUNC_MASK 0xfffffffc
+#define CPU_NUMBER(ts) ((ts & KDBG_CPU_MASK) >> KDBG_CPU_SHIFT)
+
#define DBG_ZERO_FILL_FAULT 1
#define DBG_PAGEIN_FAULT 2
#define DBG_COW_FAULT 3
int decrementer_val = 0; /* Value used to reset decrementer */
int set_remove_flag = 1; /* By default, remove trace buffer */
-/* raw read of the timebase register */
-void clock_get_uptime( register AbsoluteTime *result)
-{
-#ifdef __ppc__
-
- register UInt32 hic;
- do {
- asm volatile(" mftbu %0" : "=r" (result->hi));
- asm volatile(" mftb %0" : "=r" (result->lo));
- asm volatile(" mftbu %0" : "=r" (hic));
- } while (hic != result->hi);
-
-#else
- result->lo = 0;
- result->hi = 0;
-#endif /* __ppc__ */
-
-}
-
-typedef unsigned long long abstime_scalar_t;
-
-#define AbsoluteTime_to_scalar(x) \
- (*(abstime_scalar_t *)(x))
-
-/* t1 += t2 */
-#define ADD_ABSOLUTETIME(t1, t2) \
- (AbsoluteTime_to_scalar(t1) += \
- AbsoluteTime_to_scalar(t2))
-
-/* t1 -= t2 */
-#define SUB_ABSOLUTETIME(t1, t2) \
- (AbsoluteTime_to_scalar(t1) -= \
- AbsoluteTime_to_scalar(t2))
+kd_buf **last_decrementer_kd; /* last DECR_TRAP per cpu */
+#define MAX_LOG_COUNT 30 /* limits the number of entries dumped in log_decrementer */
int
quit(s)
sysctl(mib, 3, &kr, &needed, NULL, 0);
}
-set_rtcdec(decval)
+void set_rtcdec(decval)
int decval;
{kd_regtype kr;
int ret;
mib[5] = 0; /* no flags */
errno = 0;
-
if ((ret=sysctl(mib, 3, &kr, &needed, NULL, 0)) < 0)
{
- decrementer_val = 0;
- quit("trace facility failure, KERN_KDSETRTCDEC\n");
+ decrementer_val = 0;
+ /* ignore this sysctl error if it's not supported */
+ if (errno == ENOENT)
+ return;
+ else
+ quit("trace facility failure, KERN_KDSETRTCDEC\n");
}
}
set_enable(0);
set_pidexclude(getpid(), 0);
screen_update(log_fp);
+ endwin();
set_rtcdec(0);
set_remove();
exit(1);
}
-void sigquit()
-{
- set_enable(0);
- set_pidexclude(getpid(), 0);
- set_rtcdec(0);
- set_remove();
-
- exit(1);
-}
-
-void sigterm()
+void leave() /* exit under normal conditions -- signal handler */
{
set_enable(0);
set_pidexclude(getpid(), 0);
+ endwin();
set_rtcdec(0);
set_remove();
exit(1);
}
-
void
screen_update(FILE *fp)
{
elapsed_secs -= elapsed_mins * 60;
sprintf(tbuf, "%-19.19s %2ld:%02ld:%02ld\n", &(ctime(&curr_time)[0]),
- elapsed_hours, elapsed_mins, elapsed_secs);
+ (long)elapsed_hours, (long)elapsed_mins, (long)elapsed_secs);
if (fp)
fprintf(fp, "%s", tbuf);
else
{
fprintf(stderr, "Usage: latency [-rt] [-c codefile] [-l logfile] [-st threshold]\n");
- fprintf(stderr, " [-it threshold] [-s sleep_in_usecs]\n");
+
+#if defined (__i386__)
+ fprintf(stderr, " [-it threshold] [-s sleep_in_usecs] [-n kernel]\n\n");
+#else
+ fprintf(stderr, " [-it threshold] [-s sleep_in_usecs]\n");
fprintf(stderr, " [-d decrementer_in_usecs] [-n kernel]\n\n");
+#endif
+
fprintf(stderr, " -rt Set realtime scheduling policy. Default is timeshare.\n");
fprintf(stderr, " -c specify name of codes file\n");
fprintf(stderr, " -st set scheduler latency threshold in microseconds... if latency exceeds this, then log trace\n");
fprintf(stderr, " -it set interrupt latency threshold in microseconds... if latency exceeds this, then log trace\n");
fprintf(stderr, " -s set sleep time in microseconds\n");
+#if !defined (__i386__)
fprintf(stderr, " -d set decrementer in microseconds.\n");
+#endif
fprintf(stderr, " -n specify kernel, default is /mach_kernel\n");
fprintf(stderr, "\nlatency must be run as root\n\n");
}
-
+int
main(argc, argv)
int argc;
char *argv[];
{
- mach_timespec_t remain;
- unsigned long long start, stop;
- AbsoluteTime timestamp1;
- AbsoluteTime timestamp2;
- AbsoluteTime adeadline, adelay;
+ uint64_t start, stop;
+ uint64_t timestamp1;
+ uint64_t timestamp2;
+ uint64_t adeadline, adelay;
double fdelay;
int elapsed_usecs;
double nanosecs_to_sleep;
int loop_cnt, sample_sc_now;
int decrementer_usec = 0;
+ kern_return_t ret;
+ unsigned int size;
+ host_name_port_t host;
void getdivisor();
void sample_sc();
void init_code_file();
num_of_usecs_to_sleep = atoi(argv[1]);
else
exit_usage();
- } else if (strcmp(argv[1], "-d") == 0) {
+ }
+ else if (strcmp(argv[1], "-d") == 0) {
argc--;
argv++;
decrementer_usec = atoi(argv[1]);
else
exit_usage();
- } else if (strcmp(argv[1], "-n") == 0) {
+#if defined(__i386__)
+ /* ignore this option - setting the decrementer has no effect */
+ decrementer_usec = 0;
+#endif
+ }
+ else if (strcmp(argv[1], "-n") == 0) {
argc--;
argv++;
getdivisor();
decrementer_val = decrementer_usec * divisor;
+ /* get the cpu countfor the DECR_TRAP array */
+ host = mach_host_self();
+ size = sizeof(hi)/sizeof(int);
+ ret = host_info(host, HOST_BASIC_INFO, (host_info_t)&hi, &size);
+ if (ret != KERN_SUCCESS) {
+ mach_error(argv[0], ret);
+ exit(EXIT_FAILURE);
+ }
+
+ if ((last_decrementer_kd = (kd_buf **)malloc(hi.avail_cpus * sizeof(kd_buf *))) == (kd_buf **)0)
+ quit("can't allocate memory for decrementer tracing info\n");
+
nanosecs_to_sleep = (double)(num_of_usecs_to_sleep * 1000);
fdelay = nanosecs_to_sleep * (divisor /1000);
- AbsoluteTime_to_scalar(&adelay) = (abstime_scalar_t)fdelay;
+ adelay = (uint64_t)fdelay;
init_code_file();
*/
set_rtcdec(decrementer_val);
- initscr();
+ if (initscr() == (WINDOW *) 0)
+ {
+ printf("Unrecognized TERM type, try vt100\n");
+ exit(1);
+ }
+
clear();
refresh();
signal(SIGWINCH, sigwinch);
signal(SIGINT, sigintr);
- signal(SIGQUIT, sigquit);
- signal(SIGTERM, sigterm);
+ signal(SIGQUIT, leave);
+ signal(SIGTERM, leave);
+ signal(SIGHUP, leave);
if ((my_buffer = malloc(SAMPLE_SIZE * sizeof(kd_buf))) == (char *)0)
refresh_time = curr_time + 1;
}
- clock_get_uptime(×tamp1);
- adeadline = timestamp1;
- ADD_ABSOLUTETIME(&adeadline, &adelay);
- mk_wait_until(adeadline);
- clock_get_uptime(×tamp2);
+ timestamp1 = mach_absolute_time();
+ adeadline = timestamp1 + adelay;
+ mach_wait_until(adeadline);
+ timestamp2 = mach_absolute_time();
- start = (((unsigned long long)timestamp1.hi) << 32) |
- (unsigned long long)((unsigned int)(timestamp1.lo));
+ start = timestamp1;
- stop = (((unsigned long long)timestamp2.hi) << 32) |
- (unsigned long long)((unsigned int)(timestamp2.lo));
+ stop = timestamp2;
elapsed_usecs = (int)(((double)(stop - start)) / divisor);
}
}
if (gotSIGWINCH) {
- initscr();
+ /*
+ No need to check for initscr error return.
+ We won't get here if it fails on the first call.
+ */
+ endwin();
clear();
refresh();
gotSIGWINCH = 0;
}
}
- }
-
+}
void getdivisor()
{
+ mach_timebase_info_data_t info;
- unsigned int delta;
- unsigned int abs_to_ns_num;
- unsigned int abs_to_ns_denom;
- unsigned int proc_to_abs_num;
- unsigned int proc_to_abs_denom;
+ (void) mach_timebase_info (&info);
- (void)MKGetTimeBaseInfo (&delta, &abs_to_ns_num, &abs_to_ns_denom,
- &proc_to_abs_num, &proc_to_abs_denom);
+ divisor = ( (double)info.denom / (double)info.numer) * 1000;
- divisor = ((double)abs_to_ns_denom / (double)abs_to_ns_num) * 1000;
}
/* This is the realtime band */
size = bufinfo.nkdthreads * sizeof(kd_threadmap);
if (size)
{
- if (mapptr = (kd_threadmap *) malloc(size))
+ if ((mapptr = (kd_threadmap *) malloc(size)))
bzero (mapptr, size);
else
{
#endif
map->valid = 1;
map->thread = thread;
- (void)strncpy (map->command, command, sizeof(map->command));
- map->command[sizeof(map->command)-1] = '\0';
+ /*
+ The trace entry that returns the command name will hold
+ at most, MAXCOMLEN chars, and in that case, is not
+ guaranteed to be null terminated.
+ */
+ (void)strncpy (map->command, command, MAXCOMLEN);
+ map->command[MAXCOMLEN] = '\0';
}
{
kd_threadmap *map;
- if (map = find_thread_map(thread)) {
+ if ((map = find_thread_map(thread))) {
#if 0
if (log_fp)
}
-void sample_sc(long long start, long long stop)
+void sample_sc(uint64_t start, uint64_t stop)
{
- kd_buf *kd, *last_mach_sched, *last_decrementer_kd, *start_kd, *end_of_sample;
- unsigned long long now;
- int count;
+ kd_buf *kd, *last_mach_sched, *start_kd, *end_of_sample;
+ uint64_t now;
+ int count, i;
int first_entry = 1;
+ double timestamp = 0.0;
+ double last_timestamp = 0.0;
+ double delta = 0.0;
+ double start_bias = 0.0;
char command[32];
- double timestamp, last_timestamp, delta, start_bias;
void read_command_map();
if (log_fp && (my_policy == THREAD_TIME_CONSTRAINT_POLICY))
count = needed;
if (bufinfo.flags & KDBG_WRAPPED) {
- int i;
-
for (i = 0; i < cur_max; i++) {
th_state[i].thread = 0;
th_state[i].type = -1;
- th_state[i].vfslookup = 0;
+ th_state[i].pathptr = (long *)NULL;
th_state[i].pathname[0] = 0;
}
cur_max = 0;
}
}
end_of_sample = &((kd_buf *)my_buffer)[count];
- last_decrementer_kd = (kd_buf *)my_buffer;
+
+ /* Always reinitialize the DECR_TRAP array */
+ for (i=0; i < hi.avail_cpus; i++)
+ last_decrementer_kd[i] = (kd_buf *)my_buffer;
+
last_mach_sched = (kd_buf *)0;
for (kd = (kd_buf *)my_buffer; kd < end_of_sample; kd++) {
int debugid, thread, cpunum;
int type, clen, mode;
+ int len;
char *p;
long *sargptr;
- double i_latency;
+ kd_buf *cur_kd;
+ double i_latency = 0.0;
struct th_info *ti;
char command1[32];
char sched_info[64];
void exit_syscall();
void print_entry();
- thread = kd->arg5 & KDBG_THREAD_MASK;
- cpunum = (kd->arg5 & KDBG_CPU_MASK) ? 1: 0;
+ thread = kd->arg5;
+ cpunum = CPU_NUMBER(kd->timestamp);
debugid = kd->debugid;
type = kd->debugid & DBG_FUNC_MASK;
if (type == DECR_TRAP)
i_latency = handle_decrementer(kd);
- now = (((unsigned long long)kd->timestamp.tv_sec) << 32) |
- (unsigned long long)((unsigned int)(kd->timestamp.tv_nsec));
+ now = kd->timestamp & KDBG_TIMESTAMP_MASK;
timestamp = ((double)now) / divisor;
else if (debugid & DBG_FUNC_END)
exit_syscall(log_fp, kd, thread, type, command, timestamp, delta, start_bias, 0);
else if (type == DECR_TRAP) {
+ cur_kd = kd;
if (log_fp && i_thresh_hold && (int)i_latency > i_thresh_hold) {
- start_kd = last_decrementer_kd;
+ start_kd = last_decrementer_kd[cpunum];
kd = log_decrementer(start_kd, kd, end_of_sample, i_latency);
-
if (kd >= end_of_sample)
break;
}
- last_decrementer_kd = kd;
+ if ((kd->debugid & DBG_FUNC_MASK) == DECR_TRAP)
+ {
+ cpunum = CPU_NUMBER(kd->timestamp);
+ last_decrementer_kd[cpunum] = kd;
+ }
+ else
+ last_decrementer_kd[cpunum] = cur_kd;
}
continue;
}
if (first_entry) {
double latency;
- char buf1[128];
- char buf2[128];
+ char buf1[132];
+ char buf2[132];
latency = (double)(stop - start) / divisor;
latency -= (double)num_of_usecs_to_sleep;
}
delta = timestamp - last_timestamp;
- if (map = find_thread_map(thread))
+ if ((map = find_thread_map(thread)))
strcpy(command, map->command);
else
command[0] = 0;
break;
case DECR_TRAP:
- last_decrementer_kd = kd;
+ last_decrementer_kd[cpunum] = kd;
if (i_thresh_hold && (int)i_latency > i_thresh_hold)
p = "*";
mode = 1;
- if (ti = find_thread((kd->arg5 & KDBG_THREAD_MASK), 0, 0)) {
+ if ((ti = find_thread(kd->arg5, 0, 0))) {
if (ti->type == -1 && strcmp(command, "kernel_task"))
mode = 0;
}
case MACH_stkhandoff:
last_mach_sched = kd;
- if (map = find_thread_map(kd->arg2))
+ if ((map = find_thread_map(kd->arg2)))
strcpy(command1, map->command);
else
sprintf(command1, "%-8x", kd->arg2);
- if (ti = find_thread(kd->arg2, 0, 0)) {
+ if ((ti = find_thread(kd->arg2, 0, 0))) {
if (ti->type == -1 && strcmp(command1, "kernel_task"))
p = "U";
else
ti->thread = thread;
ti->type = -1;
- ti->vfslookup = 0;
+ ti->pathptr = (long *)0;
ti->child_thread = 0;
}
- if (ti->vfslookup == 0) {
- ti->vfslookup = 1;
+ while ( (kd < end_of_sample) && ((kd->debugid & DBG_FUNC_MASK) == VFS_LOOKUP))
+ {
+ if (ti->pathptr == NULL) {
ti->arg1 = kd->arg1;
- memset(&ti->pathname[0], 0, 32);
- sargptr = (long *)&ti->pathname[0];
+ sargptr = ti->pathname;
*sargptr++ = kd->arg2;
*sargptr++ = kd->arg3;
*sargptr++ = kd->arg4;
+ /*
+ * NULL terminate the 'string'
+ */
+ *sargptr = 0;
+ ti->pathptr = sargptr;
+
+ } else {
+ sargptr = ti->pathptr;
+
+ /*
+ We don't want to overrun our pathname buffer if the
+ kernel sends us more VFS_LOOKUP entries than we can
+ handle.
+ */
+
+ if (sargptr >= &ti->pathname[NUMPARMS])
+ {
+ kd++;
+ continue;
+ }
+
+ /*
+ We need to detect consecutive vfslookup entries.
+ So, if we get here and find a START entry,
+ fake the pathptr so we can bypass all further
+ vfslookup entries.
+ */
+
+ if (kd->debugid & DBG_FUNC_START)
+ {
+ ti->pathptr = &ti->pathname[NUMPARMS];
+ }
+ else
+ {
+ *sargptr++ = kd->arg1;
+ *sargptr++ = kd->arg2;
+ *sargptr++ = kd->arg3;
+ *sargptr++ = kd->arg4;
+ /*
+ * NULL terminate the 'string'
+ */
+ *sargptr = 0;
+
+ ti->pathptr = sargptr;
+ }
+ }
+ kd++;
+ }
+ p = (char *)ti->pathname;
- } else if (ti->vfslookup == 1) {
- ti->vfslookup = 0;
-
- sargptr = (long *)&ti->pathname[12];
- *sargptr++ = kd->arg1;
- *sargptr++ = kd->arg2;
- *sargptr++ = kd->arg3;
- *sargptr++ = kd->arg4;
+ kd--;
+
+ /* print the tail end of the pathname */
+ len = strlen(p);
+ if (len > 42)
+ len -= 42;
+ else
+ len = 0;
- if (log_fp) {
- fprintf(log_fp, "%9.1f %8.1f\t\t%-28.28s %-28s %-8x %-8x %d %s\n",
- timestamp - start_bias, delta, "VFS_LOOKUP",
- ti->pathname, ti->arg1, thread, cpunum, command);
- }
+ if (log_fp) {
+ fprintf(log_fp, "%9.1f %8.1f\t\t%-14.14s %-42s %-8x %-8x %d %s\n",
+ timestamp - start_bias, delta, "VFS_LOOKUP",
+ &p[len], ti->arg1, thread, cpunum, command);
}
+
last_timestamp = timestamp;
break;
int cpunum;
char *p;
- cpunum = (kd->arg5 & KDBG_CPU_MASK) ? 1: 0;
+ cpunum = CPU_NUMBER(kd->timestamp);
if (print_info && fp) {
- if (p = find_code(type)) {
+ if ((p = find_code(type))) {
if (type == INTERRUPT) {
int mode = 1;
- if (ti = find_thread((kd->arg5 & KDBG_THREAD_MASK), 0, 0)) {
+ if ((ti = find_thread(kd->arg5, 0, 0))) {
if (ti->type == -1 && strcmp(command, "kernel_task"))
mode = 0;
}
else
ti->type = -1;
ti->stime = timestamp;
- ti->vfslookup = 0;
+ ti->pathptr = (long *)NULL;
+
#if 0
if (print_info && fp)
fprintf(fp, "cur_max = %d, ti = %x, type = %x, thread = %x\n", cur_max, ti, ti->type, ti->thread);
int cpunum;
char *p;
- cpunum = (kd->arg5 & KDBG_CPU_MASK) ? 1: 0;
+ cpunum = CPU_NUMBER(kd->timestamp);
+
ti = find_thread(thread, type, type);
#if 0
if (print_info && fp)
else
fprintf(fp, "%9.1f %8.1f() \t", timestamp - bias, delta);
- if (p = find_code(type)) {
+ if ((p = find_code(type))) {
if (type == INTERRUPT) {
fprintf(fp, "INTERRUPT %-8x %d %s\n", thread, cpunum, command);
} else if (type == MACH_vmfault && kd->arg2 <= DBG_CACHE_HIT_FAULT) {
ti->thread = thread;
ti->child_thread = 0;
- ti->vfslookup = 0;
+ ti->pathptr = (long *)NULL;
}
}
ti->type = -1;
if (!fp)
return;
- cpunum = (kd->arg5 & KDBG_CPU_MASK) ? 1: 0;
-
+ cpunum = CPU_NUMBER(kd->timestamp);
#if 0
fprintf(fp, "cur_max = %d, type = %x, thread = %x, cpunum = %d\n", cur_max, type, thread, cpunum);
#endif
- if (p = find_code(type)) {
+ if ((p = find_code(type))) {
fprintf(fp, "%9.1f %8.1f\t\t%-28.28s %-8x %-8x %-8x %-8x %-8x %d %s\n",
timestamp - bias, delta, p, kd->arg1, kd->arg2, kd->arg3, kd->arg4,
thread, cpunum, command);
ti->thread = thread;
ti->type = -1;
- ti->vfslookup = 0;
+ ti->pathptr = (long *)NULL;
}
ti->child_thread = kd->arg1;
return (1);
kd_buf *log_decrementer(kd_buf *kd_beg, kd_buf *kd_end, kd_buf *end_of_sample, double i_latency)
{
kd_buf *kd, *kd_start, *kd_stop;
- double timestamp, last_timestamp, delta, start_bias;
+ int kd_count; /* Limit the boundary of kd_start */
+ double timestamp = 0.0;
+ double last_timestamp = 0.0;
+ double delta = 0.0;
+ double start_bias = 0.0;
int thread, cpunum;
int debugid, type, clen;
- unsigned long long now;
+ int len;
+ uint64_t now;
struct th_info *ti;
long *sargptr;
char *p;
fprintf(log_fp, "RelTime(Us) Delta debugid arg1 arg2 arg3 arg4 thread cpu command\n\n");
- thread = kd_beg->arg5 & KDBG_THREAD_MASK;
+ thread = kd_beg->arg5;
+ cpunum = CPU_NUMBER(kd_end->timestamp);
- for (kd_start = kd_beg - 1; (kd_start >= (kd_buf *)my_buffer) && (kd_start->arg5 & KDBG_THREAD_MASK) == thread; kd_start--) {
- if ((kd_start->debugid & DBG_FUNC_MASK) == DECR_TRAP)
+ for (kd_count = 0, kd_start = kd_beg - 1; (kd_start >= (kd_buf *)my_buffer); kd_start--, kd_count++) {
+ if (kd_count == MAX_LOG_COUNT)
+ break;
+
+ if (CPU_NUMBER(kd_start->timestamp) != cpunum)
+ continue;
+
+ if ((kd_start->debugid & DBG_FUNC_MASK) == DECR_TRAP)
+ break;
+
+ if (kd_start->arg5 != thread)
break;
}
+
if (kd_start < (kd_buf *)my_buffer)
kd_start = (kd_buf *)my_buffer;
- for (kd_stop = kd_end + 1; kd_stop < end_of_sample && (kd_start->arg5 & KDBG_THREAD_MASK) == thread; kd_stop++) {
- if ((kd_stop->debugid & DBG_FUNC_MASK) == DECR_TRAP)
+ thread = kd_end->arg5;
+
+ for (kd_stop = kd_end + 1; kd_stop < end_of_sample; kd_stop++) {
+
+ if ((kd_stop->debugid & DBG_FUNC_MASK) == DECR_TRAP)
+ break;
+
+ if (CPU_NUMBER(kd_stop->timestamp) != cpunum)
+ continue;
+
+ if (kd_stop->arg5 != thread)
break;
}
+
if (kd_stop >= end_of_sample)
kd_stop = end_of_sample - 1;
- now = (((unsigned long long)kd_start->timestamp.tv_sec) << 32) |
- (unsigned long long)((unsigned int)(kd_start->timestamp.tv_nsec));
+ now = kd_start->timestamp & KDBG_TIMESTAMP_MASK;
timestamp = ((double)now) / divisor;
for (kd = kd_start; kd <= kd_stop; kd++) {
type = kd->debugid & DBG_FUNC_MASK;
- if (ti = find_thread((kd->arg5 & KDBG_THREAD_MASK), type, type)) {
+ if ((ti = find_thread(kd->arg5, type, type))) {
if (ti->stime >= timestamp)
ti->type = -1;
}
for (kd = kd_start; kd <= kd_stop; kd++) {
int mode;
- thread = kd->arg5 & KDBG_THREAD_MASK;
- cpunum = (kd->arg5 & KDBG_CPU_MASK) ? 1: 0;
+ thread = kd->arg5;
+ cpunum = CPU_NUMBER(kd->timestamp);
debugid = kd->debugid;
type = kd->debugid & DBG_FUNC_MASK;
- now = (((unsigned long long)kd->timestamp.tv_sec) << 32) |
- (unsigned long long)((unsigned int)(kd->timestamp.tv_nsec));
+ now = kd->timestamp & KDBG_TIMESTAMP_MASK;
timestamp = ((double)now) / divisor;
}
delta = timestamp - last_timestamp;
- if (map = find_thread_map(thread))
+ if ((map = find_thread_map(thread)))
strcpy(command, map->command);
else
command[0] = 0;
mode = 1;
- if (ti = find_thread((kd->arg5 & KDBG_THREAD_MASK), 0, 0)) {
+ if ((ti = find_thread(kd->arg5, 0, 0))) {
if (ti->type == -1 && strcmp(command, "kernel_task"))
mode = 0;
}
case MACH_sched:
case MACH_stkhandoff:
- if (map = find_thread_map(kd->arg2))
+ if ((map = find_thread_map(kd->arg2)))
strcpy(command1, map->command);
else
sprintf(command1, "%-8x", kd->arg2);
- if (ti = find_thread(kd->arg2, 0, 0)) {
+ if ((ti = find_thread(kd->arg2, 0, 0))) {
if (ti->type == -1 && strcmp(command1, "kernel_task"))
p = "U";
else
ti->thread = thread;
ti->type = -1;
- ti->vfslookup = 0;
+ ti->pathptr = (long *)NULL;
ti->child_thread = 0;
}
- if (ti->vfslookup == 0) {
- ti->vfslookup = 1;
+
+ while ( (kd <= kd_stop) && (kd->debugid & DBG_FUNC_MASK) == VFS_LOOKUP)
+ {
+ if (ti->pathptr == NULL) {
ti->arg1 = kd->arg1;
- memset(&ti->pathname[0], 0, 32);
- sargptr = (long *)&ti->pathname[0];
+ sargptr = ti->pathname;
*sargptr++ = kd->arg2;
*sargptr++ = kd->arg3;
*sargptr++ = kd->arg4;
-
- } else if (ti->vfslookup == 1) {
- ti->vfslookup = 0;
-
- sargptr = (long *)&ti->pathname[12];
- *sargptr++ = kd->arg1;
- *sargptr++ = kd->arg2;
- *sargptr++ = kd->arg3;
- *sargptr++ = kd->arg4;
-
- fprintf(log_fp, "%9.1f %8.1f\t\t%-28.28s %-28s %-8x %-8x %d %s\n",
- timestamp - start_bias, delta, "VFS_LOOKUP",
- ti->pathname, ti->arg1, thread, cpunum, command);
+ /*
+ * NULL terminate the 'string'
+ */
+ *sargptr = 0;
+
+ ti->pathptr = sargptr;
+
+ } else {
+ sargptr = ti->pathptr;
+
+ /*
+ We don't want to overrun our pathname buffer if the
+ kernel sends us more VFS_LOOKUP entries than we can
+ handle.
+ */
+
+ if (sargptr >= &ti->pathname[NUMPARMS])
+ {
+ kd++;
+ continue;
+ }
+
+ /*
+ We need to detect consecutive vfslookup entries.
+ So, if we get here and find a START entry,
+ fake the pathptr so we can bypass all further
+ vfslookup entries.
+ */
+
+ if (kd->debugid & DBG_FUNC_START)
+ {
+ ti->pathptr = &ti->pathname[NUMPARMS];
+ }
+ else
+ {
+ *sargptr++ = kd->arg1;
+ *sargptr++ = kd->arg2;
+ *sargptr++ = kd->arg3;
+ *sargptr++ = kd->arg4;
+ /*
+ * NULL terminate the 'string'
+ */
+ *sargptr = 0;
+
+ ti->pathptr = sargptr;
+ }
+ }
+ kd++;
}
+ p = (char *)ti->pathname;
+
+ kd--;
+ /* print the tail end of the pathname */
+ len = strlen(p);
+ if (len > 42)
+ len -= 42;
+ else
+ len = 0;
+
+ fprintf(log_fp, "%9.1f %8.1f\t\t%-14.14s %-42s %-8x %-8x %d %s\n",
+ timestamp - start_bias, delta, "VFS_LOOKUP",
+ &p[len], ti->arg1, thread, cpunum, command);
+
last_timestamp = timestamp;
break;
FILE *fp = (FILE *)0;
char tmp_nm_file[128];
char tmpstr[1024];
- int inchr;
+ char inchr;
bzero(tmp_nm_file, 128);
bzero(tmpstr, 1024);
for (i=0; i<kern_sym_count; i++)
{
bzero(tmpstr, 1024);
- if (fscanf(fp, "%x %c %s", &kern_sym_tbl[i].k_sym_addr, &inchr, tmpstr) != 3)
+ if (fscanf(fp, "%lx %c %s", &kern_sym_tbl[i].k_sym_addr, &inchr, tmpstr) != 3)
break;
else
{
len = max_len - 8;
memcpy(pcstring, kern_sym_tbl[ret].k_sym_name, len);
- sprintf(&pcstring[len], "+0x%-5x", pc - kern_sym_tbl[ret].k_sym_addr);
+ sprintf(&pcstring[len], "+0x%-5lx", pc - kern_sym_tbl[ret].k_sym_addr);
return (pcstring);
}
projects / apple / system_cmds.git / blobdiff