added initial support for timestamp display

7 files changed, 65 insertions, 11 deletions

diff --git a/ChangeLog b/ChangeLog
index ae0285f..94f0c61 100644
--- a/ChangeLog
+++ b/ChangeLog
@@ -1,3 +1,9 @@
+2009-09-15  Jiri Olsa <olsajiri@gmail.com>
+	* added initial support for timestamp display
+
+-------------------------------------------------------------------------------
+latrace 0.5.7
+
 2009-09-08  Jiri Olsa <olsajiri@gmail.com>
 	* 0.5.7 latrace.spec changes
 
diff --git a/doc/latrace.txt b/doc/latrace.txt
index 937775f..6e5cb57 100644
--- a/doc/latrace.txt
+++ b/doc/latrace.txt
@@ -45,6 +45,9 @@ OPTIONS
 *-s, --sym sym1[,sym2,...]*::
 	audit symbols sym1, sym2 ...
 
+*-S, --timestamp*::
+	display timestamp for each symbol
+
 *-b, --flow-below sym1[,sym2,...]*::
 	display flow for sym1, sym2 ...
 
diff --git a/src/audit.c b/src/audit.c
index d50a01f..2b96f0d 100644
--- a/src/audit.c
+++ b/src/audit.c
@@ -73,12 +73,16 @@ static int sym_entry(const char *symname, char *lib_from, char *lib_to,
 {
 	int argret;
 	char *argbuf = "", *argdbuf = "";
+	struct timeval tv;
 
 	PRINT_VERBOSE(cfg.sh.verbose, 2, "%s@%s\n", symname, lib_to);
 
 	if (cfg.flow_below_cnt && !check_flow_below(symname, 1))
 		return 0;
 
+	if (cfg.sh.timestamp)
+		gettimeofday(&tv, NULL);
+
 	argret = cfg.sh.args_enabled ? 
 		lt_args_sym_entry(&cfg.sh, (char*) symname, regs, &argbuf, &argdbuf) : -1;
 
@@ -97,7 +101,7 @@ static int sym_entry(const char *symname, char *lib_from, char *lib_to,
 
 	cfg.sh.indent_depth++;
 
-	lt_out_entry(&cfg.sh, symname, lib_to, 
+	lt_out_entry(&cfg.sh, &tv, symname, lib_to,
 			argbuf, argdbuf);
 
 	if (!argret) {
@@ -114,12 +118,16 @@ static int sym_exit(const char *symname, char *lib_from, char *lib_to,
 {
 	int argret;
 	char *argbuf = "", *argdbuf = "";
+	struct timeval tv;
 
 	PRINT_VERBOSE(cfg.sh.verbose, 2, "%s@%s\n", symname, lib_to);
 
 	if (cfg.flow_below_cnt && !check_flow_below(symname, 0))
 		return 0;
 
+	if (cfg.sh.timestamp)
+		gettimeofday(&tv, NULL);
+
 	argret = cfg.sh.args_enabled ? 
 		lt_args_sym_exit(&cfg.sh, (char*) symname, 
 			(La_regs*) inregs, outregs, &argbuf, &argdbuf) : -1;
@@ -134,7 +142,7 @@ static int sym_exit(const char *symname, char *lib_from, char *lib_to,
 		return lt_fifo_send(&cfg, pipe_fd, buf, len);
 	}
 
-	lt_out_exit(&cfg.sh, symname, lib_from, 
+	lt_out_exit(&cfg.sh, &tv, symname, lib_from,
 			argbuf, argdbuf);
 
 	cfg.sh.indent_depth--;
diff --git a/src/config.c b/src/config.c
index 42d28b2..6b02ceb 100644
--- a/src/config.c
+++ b/src/config.c
@@ -50,6 +50,7 @@ static void usage()
 	printf("    -F, --not-follow-fork           dont follow fork calls - childs\n");
 	printf("    -E, --not-follow-exec           dont follow exec calls\n");
 	printf("\n");
+	printf("    -S, --timestamp                 display timestamp for each symbol\n");
 	printf("    -b, --flow-below sym1,sym2...   display flow only for sym1, sym2 ... \n");
 	printf("    -I, --no-indent-sym             do not indent symbols based on the their stack depth\n");
 	printf("    -i, --indent-sym indent_size    specify indent size specification\n");
@@ -123,6 +124,7 @@ int lt_config(struct lt_config_app *cfg, int argc, char **argv)
 			{"indent-sym", required_argument, 0, 'i'},
 			{"braces", no_argument, 0, 'B'},
 			{"demangle", no_argument, 0, 'd'},
+			{"timestamp", required_argument, 0, 'S'},
 			{"flow-below", required_argument, 0, 'b'},
 			{"counts", no_argument, 0, 'c'},
 			{"sort-counts", required_argument, 0, 'C'},
@@ -142,7 +144,7 @@ int lt_config(struct lt_config_app *cfg, int argc, char **argv)
 			{0, 0, 0, 0}
 		};
 
-		c = getopt_long(argc, argv, "+s:l:t:f:vhi:BdIb:cC:y:L:po:a:ADVTFE",
+		c = getopt_long(argc, argv, "+s:l:t:f:vhi:BdISb:cC:y:L:po:a:ADVTFE",
 					long_options, &option_index);
 
 		if (c == -1)
@@ -188,6 +190,10 @@ int lt_config(struct lt_config_app *cfg, int argc, char **argv)
 			cfg->sh.verbose++;
 			break;
 
+		case 'S':
+			cfg->sh.timestamp = 1;
+			break;
+
 		case 'T':
 			cfg->sh.hide_tid = 1;
 			break;
diff --git a/src/config.h b/src/config.h
index 680ab07..2aa0595 100644
--- a/src/config.h
+++ b/src/config.h
@@ -102,6 +102,7 @@ struct lt_config_shared {
 	struct hsearch_data args_tab;
 
 	int verbose;
+	int timestamp;
 	int debug;
 	int indent_sym;
 	int indent_size;
@@ -379,10 +380,12 @@ int lt_args_cb_struct(struct lt_config_shared *cfg, int type,
 			struct lt_args_data *data, int last);
 
 /* output */
-int lt_out_entry(struct lt_config_shared *cfg, const char *symname, 
-		char *lib_to, char *argbuf, char *argdbuf);
-int lt_out_exit(struct lt_config_shared *cfg, const char *symname, 
-		char *lib_to, char *argbuf, char *argdbuf);
+int lt_out_entry(struct lt_config_shared *cfg, struct timeval *tv,
+		const char *symname, char *lib_to,
+		char *argbuf, char *argdbuf);
+int lt_out_exit(struct lt_config_shared *cfg, struct timeval *tv,
+		const char *symname, char *lib_to,
+		char *argbuf, char *argdbuf);
 
 /* stack handling */
 int lt_stack_process(struct lt_config_shared *cfg, struct lt_args_sym *asym, 
diff --git a/src/output.c b/src/output.c
index b8e8bed..cadf3c6 100644
--- a/src/output.c
+++ b/src/output.c
@@ -19,6 +19,8 @@
 */
 
 #include <stdlib.h>
+#include <time.h>
+#include <sys/time.h>
 
 #include "config.h"
 
@@ -35,6 +37,22 @@ do { \
 	fprintf(cfg->fout, "%5d   ", (pid_t) syscall(SYS_gettid)); \
 } while(0)
 
+#define PRINT_TIME(tv) \
+do { \
+	struct tm t; \
+\
+	gettimeofday(tv, NULL); \
+	localtime_r(&tv->tv_sec, &t); \
+	fprintf(cfg->fout, "[%02d/%02d/%4d %02d:%02d:%02d.%06u]   ", \
+		t.tm_mon, \
+		t.tm_mday, \
+		t.tm_year + 1900, \
+		t.tm_hour, \
+		t.tm_min, \
+		t.tm_sec, \
+		(unsigned int) tv->tv_usec); \
+} while(0)
+
 /* libiberty external */
 extern char* cplus_demangle(const char *mangled, int options);
 
@@ -48,11 +66,16 @@ do { \
 	} \
 } while(0)
 
-int lt_out_entry(struct lt_config_shared *cfg, const char *symname, char *lib_to, 
+int lt_out_entry(struct lt_config_shared *cfg,
+			struct timeval *tv,
+			const char *symname, char *lib_to,
 			char *argbuf, char *argdbuf)
 {
 	int demangled = 0;
 
+	if (cfg->timestamp && tv)
+		PRINT_TIME(tv);
+
 	/* Print thread ID */
 	if (!cfg->hide_tid)
 		PRINT_TID();
@@ -84,7 +107,9 @@ int lt_out_entry(struct lt_config_shared *cfg, const char *symname, char *lib_to
 	return 0;
 }
 
-int lt_out_exit(struct lt_config_shared *cfg, const char *symname, char *lib_to, 
+int lt_out_exit(struct lt_config_shared *cfg,
+			struct timeval *tv,
+			const char *symname, char *lib_to,
 			char *argbuf, char *argdbuf)
 {
 	int demangled = 0;
@@ -92,6 +117,9 @@ int lt_out_exit(struct lt_config_shared *cfg, const char *symname, char *lib_to,
 	if (!*argbuf && (!cfg->braces))
 		return 0;
 
+	if (cfg->timestamp && tv)
+		PRINT_TIME(tv);
+
 	/* Print thread ID */
 	if (!cfg->hide_tid)
 		PRINT_TID();
diff --git a/src/run.c b/src/run.c
index 23eb983..d328964 100644
--- a/src/run.c
+++ b/src/run.c
@@ -133,7 +133,7 @@ static int process_fifo(struct lt_config_app *cfg, struct lt_thread *t)
 	if (FIFO_MSG_TYPE_ENTRY == msym->h.type) {
 
 		cfg->sh.indent_depth++;
-		lt_out_entry(&cfg->sh,
+		lt_out_entry(&cfg->sh, NULL,
 				msym->data + msym->sym,
 				msym->data + msym->lib,
 				msym->data + msym->arg,
@@ -141,7 +141,7 @@ static int process_fifo(struct lt_config_app *cfg, struct lt_thread *t)
 
 	} else if (FIFO_MSG_TYPE_EXIT == msym->h.type) {
 
-		lt_out_exit(&cfg->sh,
+		lt_out_exit(&cfg->sh, NULL,
 				msym->data + msym->sym,
 				msym->data + msym->lib,
 				msym->data + msym->arg,