Version 0.3.30
* Implemented -T option (show time spent inside each call)
* Alphabetically sort options in help and manual page
* Added -c option (summary of calls on program exit)
diff --git a/Makefile.in b/Makefile.in
index 2ca7e1f..a79b346 100644
--- a/Makefile.in
+++ b/Makefile.in
@@ -22,7 +22,7 @@
OBJ = ltrace.o options.o elf.o output.o read_config_file.o \
execute_program.o wait_for_something.o process_event.o \
display_args.o breakpoints.o proc.o demangle.o dict.o \
- debug.o
+ debug.o summary.o
all: ltrace
diff --git a/debian/changelog b/debian/changelog
index 942f214..4a86b2f 100644
--- a/debian/changelog
+++ b/debian/changelog
@@ -1,3 +1,11 @@
+ltrace (0.3.30) unstable; urgency=low
+
+ * Implemented -T option (show time spent inside each call)
+ * Alphabetically sort options in help and manual page
+ * Added -c option (summary of calls on program exit)
+
+ -- Juan Cespedes <cespedes@debian.org> Mon, 03 Feb 2003 00:22:28 +0100
+
ltrace (0.3.29) unstable; urgency=low
* Align return values depending on screen width
diff --git a/ltrace.1 b/ltrace.1
index ed7f967..87fc71c 100644
--- a/ltrace.1
+++ b/ltrace.1
@@ -6,7 +6,7 @@
.SH SYNOPSIS
.B ltrace
-.I "[-dfiLSrtttChV] [-a column] [-s strsize] [-o filename] [-n nr] [-l filename] [-u username] [-p pid] ... [-e expr] [--debug] [--demangle] [--align=column] [--output=filename] [--indent=nr] [--library=filename] [--help] [--version] [command [arg ...]]"
+.I "[-CdfhiLrStttV] [-a column] [-e expr] [-l filename] [-n nr] [-o filename] [-p pid] ... [-s strsize] [-u username] [--align=column] [--debug] [--demangle] [--help] [--indent=nr] [--library=filename] [--output=filename] [--version] [command [arg ...]]"
.SH DESCRIPTION
.B ltrace
@@ -22,83 +22,22 @@
.SH OPTIONS
.TP
-.I \-d, \-\-debug
-Increase the debugging level.
-Use more (ie.
-.I \=dd
-) for greater debugging information.
+.I \-a, \-\-align column
+Align return values in a secific column (default column is 5/8 of screen width).
.TP
-.I \-f
-Trace child processes as they are created by
-currently traced processes as a result of the fork(2)
-or clone(2) system calls.
-The new process is attached as soon as its pid is known.
-.TP
-.I \-i
-Print the instruction pointer at the time of the library call.
-.TP
-.I \-L
-DON'T display library calls (use it with the
-.I \-S
-option).
-.TP
-.I \-S
-Display system calls as well as library calls
-.TP
-.I \-r
-Print a relative timestamp with each line of the trace.
-This records the time difference between the beginning of
-successive lines.
-.TP
-.I \-t
-Prefix each line of the trace with the time of day.
-.TP
-.I \-tt
-If given twice, the time printed will include the microseconds.
-.TP
-.I \-ttt
-If given thrice, the time printed will include the microseconds and
-the leading portion will be printed as the number of seconds since the
-epoch.
+.I \-c
+Count time and calls for each library call and report a summary on program exit.
.TP
.I \-C, \-\-demangle
Decode (demangle) low-level symbol names into user-level names.
Besides removing any initial underscore prepended by the system,
this makes C++ function names readable.
.TP
-.I \-a, \-\-align column
-Align return values in a secific column (default column is 5/8 of screen width).
-.TP
-.I \-s
-Specify the maximum string size to print (the default is 32).
-.TP
-.I \-o, \-\-output filename
-Write the trace output to the file
-.I filename
-rather than to stderr.
-.TP
-.I \-n, \-\-indent nr
-Indent trace output by
-.I nr
-number of spaces for each new nested call. Using this option makes
-the program flow visualization easy to follow.
-.TP
-.I \-l, \-\-library filename
-Display only the symbols included in the library
-.I filename.
-Up to 20 library names can be specified with several instances
-of this option.
-.TP
-.I \-u username
-Run command with the userid, groupid and supplementary groups of
-.IR username .
-This option is only useful when running as root and enables the
-correct execution of setuid and/or setgid binaries.
-.TP
-.I \-p pid
-Attach to the process with the process ID
-.I pid
-and begin tracing.
+.I \-d, \-\-debug
+Increase the debugging level.
+Use more (ie.
+.I \=dd
+) for greater debugging information.
.TP
.I \-e expr
A qualifying expression which modifies which events to trace.
@@ -117,9 +56,77 @@
expansion; even inside quoted arguments. If so, you must escape
the exclamation point with a backslash.
.TP
+.I \-f
+Trace child processes as they are created by
+currently traced processes as a result of the fork(2)
+or clone(2) system calls.
+The new process is attached as soon as its pid is known.
+.TP
.I \-h, \-\-help
Show a summary of the options to ltrace and exit.
.TP
+.I \-i
+Print the instruction pointer at the time of the library call.
+.TP
+.I \-l, \-\-library filename
+Display only the symbols included in the library
+.I filename.
+Up to 20 library names can be specified with several instances
+of this option.
+.TP
+.I \-L
+DON'T display library calls (use it with the
+.I \-S
+option).
+.TP
+.I \-n, \-\-indent nr
+Indent trace output by
+.I nr
+number of spaces for each new nested call. Using this option makes
+the program flow visualization easy to follow.
+.TP
+.I \-o, \-\-output filename
+Write the trace output to the file
+.I filename
+rather than to stderr.
+.TP
+.I \-p pid
+Attach to the process with the process ID
+.I pid
+and begin tracing.
+.TP
+.I \-r
+Print a relative timestamp with each line of the trace.
+This records the time difference between the beginning of
+successive lines.
+.TP
+.I \-s strsize
+Specify the maximum string size to print (the default is 32).
+.TP
+.I \-S
+Display system calls as well as library calls
+.TP
+.I \-t
+Prefix each line of the trace with the time of day.
+.TP
+.I \-tt
+If given twice, the time printed will include the microseconds.
+.TP
+.I \-ttt
+If given thrice, the time printed will include the microseconds and
+the leading portion will be printed as the number of seconds since the
+epoch.
+.TP
+.I \-T
+Show the time spent inside each call. This records the time difference
+between the beginning and the end of each call.
+.TP
+.I \-u username
+Run command with the userid, groupid and supplementary groups of
+.IR username .
+This option is only useful when running as root and enables the
+correct execution of setuid and/or setgid binaries.
+.TP
.I \-V, \-\-version
Show the version number of ltrace and exit.
diff --git a/ltrace.c b/ltrace.c
index 461e745..9bc39a9 100644
--- a/ltrace.c
+++ b/ltrace.c
@@ -71,6 +71,9 @@
static void
normal_exit(void) {
output_line(0,0);
+ if (opt_c) {
+ summary();
+ }
}
static void
diff --git a/ltrace.h b/ltrace.h
index 8d6c6b4..b4f4adf 100644
--- a/ltrace.h
+++ b/ltrace.h
@@ -2,6 +2,7 @@
#define _HCK_LTRACE_H
#include <sys/types.h>
+#include <sys/time.h>
#include <stdio.h>
#include "defs.h"
@@ -70,6 +71,7 @@
} c_un;
int is_syscall;
void * return_addr;
+ struct timeval time_spent;
};
#define MAX_CALLDEPTH 64
@@ -116,6 +118,12 @@
} e_un;
};
+struct opt_c_struct {
+ int count;
+ struct timeval tv;
+};
+extern struct dict * dict_opt_c;
+
extern struct process * list_of_processes;
extern void * instruction_pointer;
diff --git a/opt_c.c b/opt_c.c
new file mode 100644
index 0000000..4deff24
--- /dev/null
+++ b/opt_c.c
@@ -0,0 +1,182 @@
+#if HAVE_CONFIG_H
+#include "config.h"
+#endif
+
+#include <stdio.h>
+#include <stdlib.h>
+#include <unistd.h>
+#include <string.h>
+#include <errno.h>
+#include <sys/param.h>
+#include <signal.h>
+#include <sys/wait.h>
+#include <sys/ioctl.h>
+
+#include "ltrace.h"
+#include "output.h"
+#include "read_config_file.h"
+#include "options.h"
+#include "debug.h"
+
+#ifndef SYSCONFDIR
+#define SYSCONFDIR "/etc"
+#endif
+
+char * command = NULL;
+struct process * list_of_processes = NULL;
+
+int exiting=0; /* =1 if a SIGINT or SIGTERM has been received */
+
+static void
+signal_alarm(int sig) {
+ struct process * tmp = list_of_processes;
+
+ signal(SIGALRM,SIG_DFL);
+ while(tmp) {
+ struct opt_p_t * tmp2 = opt_p;
+ while(tmp2) {
+ if (tmp->pid == tmp2->pid) {
+ tmp = tmp->next;
+ if (!tmp) {
+ return;
+ }
+ break;
+ }
+ tmp2 = tmp2->next;
+ }
+ debug(2,"Sending SIGSTOP to process %u\n",tmp->pid);
+ kill(tmp->pid, SIGSTOP);
+ tmp = tmp->next;
+ }
+}
+
+static void
+signal_exit(int sig) {
+ exiting=1;
+ debug(1,"Received interrupt signal; exiting...");
+ signal(SIGINT,SIG_IGN);
+ signal(SIGTERM,SIG_IGN);
+ signal(SIGALRM,signal_alarm);
+ if (opt_p) {
+ struct opt_p_t * tmp = opt_p;
+ while(tmp) {
+ debug(2,"Sending SIGSTOP to process %u\n",tmp->pid);
+ kill(tmp->pid, SIGSTOP);
+ tmp = tmp->next;
+ }
+ }
+ alarm(1);
+}
+
+struct opt_c_struct2 {
+ int num;
+ struct {
+ char *name;
+ int count;
+ struct timeval tv;
+ } st[0];
+};
+
+static void
+opt_c_show_func(void * key, void * value, void * data) {
+ struct opt_c_struct * st = (struct opt_c_struct *)value;
+// unsigned long int c;
+ struct opt_c_struct2 * st2 = (struct opt_c_struct2 *)data;
+ int num = st2->num;
+
+ st2 = realloc(st2, sizeof(struct opt_c_struct2)+ (num+1)*sizeof(st2->st[0]));
+ if (!st2) {
+ perror("realloc()");
+ exit(1);
+ }
+ st2->num++;
+ st2->st[num].name = (char *)key;
+ st2->st[num].count = st->count;
+ st2->st[num].tv = st->tv;
+// c = 1000000 * (int)st->tv.tv_sec + (int)st->tv.tv_usec;
+// c /= st->count;
+// printf("%3d.%02d %4d.%06d %11lu %9d %s\n", 99, 99,
+// (int)st->tv.tv_sec, (int)st->tv.tv_usec,
+// c, st->count, (char *)key);
+}
+
+static void
+normal_exit(void) {
+ output_line(0,0);
+ if (opt_c) {
+ struct opt_c_struct2 * st2 = malloc(sizeof(struct opt_c_struct2));
+
+ if (!st2) {
+ perror("malloc()");
+ exit(1);
+ }
+ st2->num = 0;
+ printf("%% time seconds usecs/call calls function\n");
+ printf( "------ ----------- ----------- --------- --------------------\n");
+ dict_apply_to_all(dict_opt_c, opt_c_show_func, st2);
+ printf( "------ ----------- ----------- --------- --------------------\n");
+ printf( "100.00 0.000360 27 total\n");
+ }
+}
+
+static void
+guess_cols(void) {
+ struct winsize ws;
+ char * c;
+
+ opt_a = DEFAULT_ACOLUMN;
+ c = getenv("COLUMNS");
+ if (c && *c) {
+ char * endptr;
+ int cols;
+ cols = strtol(c, &endptr, 0);
+ if (cols>0 && !*endptr) {
+ opt_a = cols * 5/8;
+ }
+ } else if (ioctl(1, TIOCGWINSZ, &ws) != -1 && ws.ws_col>0) {
+ opt_a = ws.ws_col * 5/8;
+ }
+}
+
+int
+main(int argc, char **argv) {
+ struct opt_p_t * opt_p_tmp;
+ char * home;
+
+ atexit(normal_exit);
+ signal(SIGINT,signal_exit); /* Detach processes when interrupted */
+ signal(SIGTERM,signal_exit); /* ... or killed */
+
+ guess_cols();
+ argv = process_options(argc, argv);
+ read_config_file(SYSCONFDIR "/ltrace.conf");
+ home = getenv("HOME");
+ if (home) {
+ char path[PATH_MAX];
+ if (strlen(home) > PATH_MAX-15) {
+ fprintf(stderr, "Error: $HOME too long\n");
+ exit(1);
+ }
+ strcpy(path, getenv("HOME"));
+ strcat(path, "/.ltrace.conf");
+ read_config_file(path);
+ }
+ if (opt_e) {
+ struct opt_e_t * tmp = opt_e;
+ while(tmp) {
+ debug(1,"Option -e: %s\n", tmp->name);
+ tmp = tmp->next;
+ }
+ }
+ if (command) {
+ execute_program(open_program(command), argv);
+ }
+ opt_p_tmp = opt_p;
+ while (opt_p_tmp) {
+ open_pid(opt_p_tmp->pid, 1);
+ opt_p_tmp = opt_p_tmp->next;
+ }
+ while(1) {
+ process_event(wait_for_something());
+ }
+}
diff --git a/options.c b/options.c
index fe4aee7..326565d 100644
--- a/options.c
+++ b/options.c
@@ -3,7 +3,7 @@
#endif
#ifndef VERSION
-# define VERSION "0.3.29"
+# define VERSION "0.3.30"
#endif
#include <string.h>
@@ -27,6 +27,7 @@
static char *progname; /* Program name (`ltrace') */
FILE * output;
int opt_a = DEFAULT_ACOLUMN; /* default alignment column for results */
+int opt_c = 0; /* Count time, calls, and report a summary on program exit */
int opt_d = 0; /* debug */
int opt_i = 0; /* instruction pointer */
int opt_s = DEFAULT_STRLEN; /* default maximum # of bytes printed in strings */
@@ -40,6 +41,7 @@
int opt_C = 0; /* Demangle low-level symbol names into user-level names */
#endif
int opt_n = 0; /* indent trace output according to program flow */
+int opt_T = 0; /* show the time spent inside each call */
/* List of pids given to option -p: */
struct opt_p_t * opt_p = NULL; /* attach to process with a given pid */
@@ -58,21 +60,11 @@
"Trace library calls of a given program.\n\n"
# if HAVE_GETOPT_LONG
-" -d, --debug print debugging info.\n"
+" -a, --align=COLUMN align return values in a secific column.\n"
# else
-" -d print debugging info.\n"
+" -a COLUMN align return values in a secific column.\n"
# endif
-" -f follow forks.\n"
-" -i print instruction pointer at time of library call.\n"
-" -L do NOT display library calls.\n"
-" -S display system calls.\n"
-" -r print relative timestamps.\n"
-" -t, -tt, -ttt print absolute timestamps.\n"
-# if HAVE_GETOPT_LONG
-" -l, --library=FILE print library calls from this library only.\n"
-# else
-" -l FILE print library calls from this library only.\n"
-# endif
+" -c count time and calls, and report a summary on exit.\n"
# if HAVE_LIBIBERTY
# if HAVE_GETOPT_LONG
" -C, --demangle decode low-level symbol names into user-level names.\n"
@@ -81,29 +73,41 @@
# endif
# endif
# if HAVE_GETOPT_LONG
-" -a, --align=COLUMN align return values in a secific column.\n"
+" -d, --debug print debugging info.\n"
# else
-" -a COLUMN align return values in a secific column.\n"
+" -d print debugging info.\n"
# endif
-" -s STRLEN specify the maximum string size to print.\n"
-# if HAVE_GETOPT_LONG
-" -o, --output=FILE write the trace output to that file.\n"
-# else
-" -o FILE write the trace output to that file.\n"
-# endif
-" -u USERNAME run command with the userid, groupid of username.\n"
-" -p PID attach to the process with the process ID pid.\n"
" -e expr modify which events to trace.\n"
+" -f follow forks.\n"
+# if HAVE_GETOPT_LONG
+" -h, --help display this help and exit.\n"
+# else
+" -h display this help and exit.\n"
+# endif
+" -i print instruction pointer at time of library call.\n"
+# if HAVE_GETOPT_LONG
+" -l, --library=FILE print library calls from this library only.\n"
+# else
+" -l FILE print library calls from this library only.\n"
+# endif
+" -L do NOT display library calls.\n"
# if HAVE_GETOPT_LONG
" -n, --indent=NR indent output by NR spaces for each call level nesting.\n"
# else
" -n NR indent output by NR spaces for each call level nesting.\n"
# endif
# if HAVE_GETOPT_LONG
-" -h, --help display this help and exit.\n"
+" -o, --output=FILE write the trace output to that file.\n"
# else
-" -h display this help and exit.\n"
+" -o FILE write the trace output to that file.\n"
# endif
+" -p PID attach to the process with the process ID pid.\n"
+" -r print relative timestamps.\n"
+" -s STRLEN specify the maximum string size to print.\n"
+" -S display system calls.\n"
+" -t, -tt, -ttt print absolute timestamps.\n"
+" -T show the time spent inside each call.\n"
+" -u USERNAME run command with the userid, groupid of username.\n"
# if HAVE_GETOPT_LONG
" -V, --version output version information and exit.\n"
# else
@@ -163,82 +167,38 @@
{ "demangle", 0, 0, 'C'},
#endif
{ "indent", 0, 0, 'n'},
- { "library", 0, 0, 'l'},
{ "help", 0, 0, 'h'},
+ { "library", 0, 0, 'l'},
{ "output", 1, 0, 'o'},
{ "version", 0, 0, 'V'},
{ 0, 0, 0, 0}
};
- c = getopt_long(argc, argv, "+dfiLSrthV"
+ c = getopt_long(argc, argv, "+cdfhiLrStTV"
# if HAVE_LIBIBERTY
"C"
# endif
- "a:s:o:u:p:e:n:l:", long_options, &option_index);
+ "a:e:l:n:o:p:s:u:", long_options, &option_index);
#else
- c = getopt(argc, argv, "+dfiLSrthV"
+ c = getopt(argc, argv, "+cdfhiLrStTV"
# if HAVE_LIBIBERTY
"C"
# endif
- "a:s:o:u:p:e:n:l:");
+ "a:e:l:n:o:p:s:u:");
#endif
if (c==-1) {
break;
}
switch(c) {
- case 'l': if (library_num == MAX_LIBRARY) {
- fprintf(stderr, "Too many libraries. Maximum is %i.\n", MAX_LIBRARY);
- exit(1);
- }
- library[library_num++] = optarg;
- break;
- case 'd': opt_d++;
- break;
- case 'f': opt_f = 1;
- break;
- case 'i': opt_i++;
- break;
- case 'L': opt_L = 0;
- break;
- case 'S': opt_S = 1;
- break;
- case 'r': opt_r++;
- break;
- case 't': opt_t++;
- break;
+ case 'a': opt_a = atoi(optarg);
+ break;
+ case 'c': opt_c++;
+ break;
#if HAVE_LIBIBERTY
case 'C': opt_C++;
- break;
+ break;
#endif
- case 'a': opt_a = atoi(optarg);
- break;
- case 's': opt_s = atoi(optarg);
- break;
- case 'n': opt_n = atoi(optarg);
- break;
- case 'h': usage();
- exit(0);
- case 'o': output = fopen(optarg, "w");
- if (!output) {
- fprintf(stderr, "Can't open %s for output: %s\n", optarg, strerror(errno));
- exit(1);
- }
- setvbuf(output, (char *)NULL, _IOLBF, 0);
- fcntl(fileno(output), F_SETFD, FD_CLOEXEC);
- break;
- case 'u': opt_u = optarg;
- break;
- case 'p':
- {
- struct opt_p_t * tmp = malloc(sizeof(struct opt_p_t));
- if (!tmp) {
- perror("ltrace: malloc");
- exit(1);
- }
- tmp->pid = atoi(optarg);
- tmp->next = opt_p;
- opt_p = tmp;
- break;
- }
+ case 'd': opt_d++;
+ break;
case 'e':
{
char * str_e = strdup(optarg);
@@ -272,19 +232,67 @@
}
break;
}
+ case 'f': opt_f = 1;
+ break;
+ case 'h': usage();
+ exit(0);
+ case 'i': opt_i++;
+ break;
+ case 'l': if (library_num == MAX_LIBRARY) {
+ fprintf(stderr, "Too many libraries. Maximum is %i.\n", MAX_LIBRARY);
+ exit(1);
+ }
+ library[library_num++] = optarg;
+ break;
+ case 'L': opt_L = 0;
+ break;
+ case 'n': opt_n = atoi(optarg);
+ break;
+ case 'o': output = fopen(optarg, "w");
+ if (!output) {
+ fprintf(stderr, "Can't open %s for output: %s\n", optarg, strerror(errno));
+ exit(1);
+ }
+ setvbuf(output, (char *)NULL, _IOLBF, 0);
+ fcntl(fileno(output), F_SETFD, FD_CLOEXEC);
+ break;
+ case 'p':
+ {
+ struct opt_p_t * tmp = malloc(sizeof(struct opt_p_t));
+ if (!tmp) {
+ perror("ltrace: malloc");
+ exit(1);
+ }
+ tmp->pid = atoi(optarg);
+ tmp->next = opt_p;
+ opt_p = tmp;
+ break;
+ }
+ case 'r': opt_r++;
+ break;
+ case 's': opt_s = atoi(optarg);
+ break;
+ case 'S': opt_S = 1;
+ break;
+ case 't': opt_t++;
+ break;
+ case 'T': opt_T++;
+ break;
+ case 'u': opt_u = optarg;
+ break;
case 'V': printf("ltrace version " VERSION ".\n"
"Copyright (C) 1997-2002 Juan Cespedes <cespedes@debian.org>.\n"
"This is free software; see the GNU General Public Licence\n"
"version 2 or later for copying conditions. There is NO warranty.\n");
- exit(0);
+ exit(0);
default:
#if HAVE_GETOPT_LONG
- fprintf(stderr, "Try `%s --help' for more information\n", progname);
+ fprintf(stderr, "Try `%s --help' for more information\n", progname);
#else
- fprintf(stderr, "Try `%s -h' for more information\n", progname);
+ fprintf(stderr, "Try `%s -h' for more information\n", progname);
#endif
- exit(1);
+ exit(1);
}
}
argc -= optind; argv += optind;
diff --git a/options.h b/options.h
index 60ccade..86c1694 100644
--- a/options.h
+++ b/options.h
@@ -7,6 +7,7 @@
extern FILE * output;
extern int opt_a; /* default alignment column for results */
+extern int opt_c; /* count time, calls, and report a summary on program exit */
extern int opt_d; /* debug */
extern int opt_i; /* instruction pointer */
extern int opt_s; /* default maximum # of bytes printed in strings */
@@ -20,6 +21,7 @@
extern int opt_C; /* Demanglelow-level symbol names into user-level names */
#endif
extern int opt_n; /* indent trace output according to program flow */
+extern int opt_T; /* show the time spent inside each call */
struct opt_p_t {
pid_t pid;
diff --git a/output.c b/output.c
index 4a773a7..c29e5cd 100644
--- a/output.c
+++ b/output.c
@@ -3,6 +3,7 @@
#endif
#include <stdio.h>
+#include <stdlib.h>
#include <stdarg.h>
#include <string.h>
#include <time.h>
@@ -12,11 +13,17 @@
#include "ltrace.h"
#include "options.h"
#include "output.h"
+#include "dict.h"
#if HAVE_LIBIBERTY
#include "demangle.h"
#endif
+/* TODO FIXME XXX: include in ltrace.h: */
+extern struct timeval current_time_spent;
+
+struct dict * dict_opt_c = NULL;
+
static pid_t current_pid = 0;
static int current_depth = 0;
static int current_column = 0;
@@ -120,6 +127,9 @@
output_line(struct process * proc, char *fmt, ...) {
va_list args;
+ if (opt_c) {
+ return;
+ }
if (current_pid) {
fprintf(output, " <unfinished ...>\n");
}
@@ -147,6 +157,9 @@
output_left(enum tof type, struct process * proc, char * function_name) {
struct function * func;
+ if (opt_c) {
+ return;
+ }
if (current_pid) {
fprintf(output, " <unfinished ...>\n");
current_pid=0;
@@ -190,6 +203,37 @@
output_right(enum tof type, struct process * proc, char * function_name) {
struct function * func = name2func(function_name);
+ if (opt_c) {
+ struct opt_c_struct * st;
+ if (!dict_opt_c) {
+ dict_opt_c = dict_init(dict_key2hash_string, dict_key_cmp_string);
+ }
+ st = dict_find_entry(dict_opt_c, function_name);
+ if (!st) {
+ char *na;
+ st = malloc(sizeof(struct opt_c_struct));
+ na = strdup(function_name);
+ if (!st || !na) {
+ perror("malloc()");
+ exit(1);
+ }
+ st->count = 0;
+ st->tv.tv_sec = st->tv.tv_usec = 0;
+ dict_enter(dict_opt_c, na, st);
+ }
+ if (st->tv.tv_usec + current_time_spent.tv_usec > 1000000) {
+ st->tv.tv_usec += current_time_spent.tv_usec - 1000000;
+ st->tv.tv_sec++;
+ } else {
+ st->tv.tv_usec += current_time_spent.tv_usec;
+ }
+ st->count++;
+ st->tv.tv_sec += current_time_spent.tv_sec;
+
+// fprintf(output, "%s <%lu.%06d>\n", function_name,
+// current_time_spent.tv_sec, (int)current_time_spent.tv_usec);
+ return;
+ }
if (current_pid && (current_pid!=proc->pid ||
current_depth != proc->callstack_depth)) {
fprintf(output, " <unfinished ...>\n");
@@ -209,7 +253,6 @@
tabto(opt_a-1);
fprintf(output, "= ");
display_arg(type, proc, -1, ARGTYPE_UNKNOWN);
- fprintf(output, "\n");
} else {
int i;
for(i=func->num_params-func->params_right; i<func->num_params-1; i++) {
@@ -227,8 +270,12 @@
} else {
display_arg(type, proc, -1, func->return_type);
}
- fprintf(output, "\n");
}
+ if (opt_T) {
+ fprintf(output, " <%lu.%06d>",
+ current_time_spent.tv_sec, (int)current_time_spent.tv_usec);
+ }
+ fprintf(output, "\n");
current_pid=0;
current_column=0;
}
diff --git a/process_event.c b/process_event.c
index 9c95634..ba47084 100644
--- a/process_event.c
+++ b/process_event.c
@@ -8,6 +8,7 @@
#include <stdlib.h>
#include <signal.h>
#include <assert.h>
+#include <sys/time.h>
#include "ltrace.h"
#include "output.h"
@@ -156,17 +157,43 @@
if (opt_S) {
output_left(LT_TOF_SYSCALL, event->proc, sysname(event->e_un.sysnum));
}
- callstack_push_syscall(event->proc, event->e_un.sysnum);
if (fork_p(event->e_un.sysnum)) {
disable_all_breakpoints(event->proc);
} else if (!event->proc->breakpoints_enabled) {
enable_all_breakpoints(event->proc);
}
+ callstack_push_syscall(event->proc, event->e_un.sysnum);
continue_process(event->proc->pid);
}
+struct timeval current_time_spent;
+
+static void
+calc_time_spent(struct process * proc) {
+ struct timeval tv;
+ struct timezone tz;
+ struct timeval diff;
+ struct callstack_element * elem;
+
+ elem = & proc->callstack[proc->callstack_depth-1];
+
+ gettimeofday(&tv, &tz);
+
+ diff.tv_sec = tv.tv_sec - elem->time_spent.tv_sec;
+ if (tv.tv_usec >= elem->time_spent.tv_usec) {
+ diff.tv_usec = tv.tv_usec - elem->time_spent.tv_usec;
+ } else {
+ diff.tv_sec++;
+ diff.tv_usec = 1000000 + tv.tv_usec - elem->time_spent.tv_usec;
+ }
+ current_time_spent = diff;
+}
+
static void
process_sysret(struct event * event) {
+ if (opt_T || opt_c) {
+ calc_time_spent(event->proc);
+ }
if (fork_p(event->e_un.sysnum)) {
if (opt_f) {
pid_t child = gimme_arg(LT_TOF_SYSCALL,event->proc,-1);
@@ -222,9 +249,13 @@
insert_breakpoint(event->proc, addr);
}
#endif
- for(j=event->proc->callstack_depth-1; j>=i; j--) {
+ for(j=event->proc->callstack_depth-1; j>i; j--) {
callstack_pop(event->proc);
}
+ if (opt_T || opt_c) {
+ calc_time_spent(event->proc);
+ }
+ callstack_pop(event->proc);
event->proc->return_addr = event->e_un.brk_addr;
output_right(LT_TOF_FUNCTION, event->proc,
event->proc->callstack[i].c_un.libfunc->name);
@@ -267,6 +298,10 @@
elem->return_addr = NULL;
proc->callstack_depth++;
+ if (opt_T || opt_c) {
+ struct timezone tz;
+ gettimeofday(&elem->time_spent, &tz);
+ }
}
static void
@@ -287,6 +322,10 @@
insert_breakpoint(proc, elem->return_addr);
proc->callstack_depth++;
+ if (opt_T || opt_c) {
+ struct timezone tz;
+ gettimeofday(&elem->time_spent, &tz);
+ }
}
static void
diff --git a/summary.c b/summary.c
new file mode 100644
index 0000000..a612b70
--- /dev/null
+++ b/summary.c
@@ -0,0 +1,79 @@
+#include <stdio.h>
+#include <stdlib.h>
+#include <sys/time.h>
+
+#include "ltrace.h"
+
+static int num_entries = 0;
+static struct entry_st {
+ char *name;
+ int count;
+ struct timeval tv;
+} * entries = NULL;
+
+static int tot_count = 0;
+static unsigned long int tot_usecs = 0;
+
+static void
+fill_struct(void * key, void * value, void * data) {
+ struct opt_c_struct * st = (struct opt_c_struct *)value;
+
+ entries = realloc(entries, (num_entries+1)*sizeof(struct entry_st));
+ if (!entries) {
+ perror("realloc()");
+ exit(1);
+ }
+ entries[num_entries].name = (char *)key;
+ entries[num_entries].count = st->count;
+ entries[num_entries].tv = st->tv;
+
+ tot_count += st->count;
+ tot_usecs += 1000000*st->tv.tv_sec;
+ tot_usecs += st->tv.tv_usec;
+
+ num_entries++;
+}
+
+static int
+compar(const void *a, const void *b) {
+ struct entry_st *en1, *en2;
+
+ en1 = (struct entry_st *)a;
+ en2 = (struct entry_st *)b;
+
+ if (en2->tv.tv_sec - en1->tv.tv_sec) {
+ return (en2->tv.tv_sec - en1->tv.tv_sec);
+ } else {
+ return (en2->tv.tv_usec - en1->tv.tv_usec);
+ }
+}
+
+void
+summary(void) {
+ int i;
+
+ num_entries = 0;
+ entries = NULL;
+
+ dict_apply_to_all(dict_opt_c, fill_struct, NULL);
+
+ qsort(entries, num_entries, sizeof(*entries), compar);
+
+ printf("%% time seconds usecs/call calls function\n");
+ printf( "------ ----------- ----------- --------- --------------------\n");
+ for(i=0; i<num_entries; i++) {
+ unsigned long long int c;
+ unsigned long long int p;
+ c = 1000000 * (int)entries[i].tv.tv_sec + (int)entries[i].tv.tv_usec;
+ p = 100000 * c / tot_usecs + 5;
+ printf("%3lu.%02d %4d.%06d %11lu %9d %s\n",
+ (unsigned long int)(p / 1000),
+ (unsigned long int)((p / 10) % 100),
+ (int)entries[i].tv.tv_sec, (int)entries[i].tv.tv_usec,
+ (unsigned long int)(c / entries[i].count),
+ entries[i].count, entries[i].name);
+ }
+ printf("------ ----------- ----------- --------- --------------------\n");
+ printf("100.00 %4lu.%06lu %9d total\n",
+ tot_usecs / 1000000, tot_usecs % 1000000, tot_count);
+}