From: David van Moolenbroek Date: Thu, 15 Dec 2016 18:05:51 +0000 (+0000) Subject: trace(1): add basic support for timestamps X-Git-Url: http://zhaoyanbai.com/repos/%22http:/www.isc.org/icons/zpipe.c?a=commitdiff_plain;h=refs%2Fchanges%2F82%2F3382%2F1;p=minix.git trace(1): add basic support for timestamps This patch adds strace-like support for a -t command line option, which causes a timestamp to be printed at the beginning of each line. If the option is given more than once, the output will also include microseconds. Change-Id: I8cda581651859448c154b01815cc49d915b7b354 --- diff --git a/minix/usr.bin/trace/output.c b/minix/usr.bin/trace/output.c index f87416378..10bd8c84a 100644 --- a/minix/usr.bin/trace/output.c +++ b/minix/usr.bin/trace/output.c @@ -165,15 +165,18 @@ output_flush(void) } /* - * Print a PID prefix for the given process, or an info prefix if no process - * (NULL) is given. Prefixes are only relevant when multiple processes are - * traced. As long as there are multiple processes, each line is prefixed with - * the PID of the process. As soon as the number of processes has been reduced - * back to one, one more line is prefixed with the PID of the remaining process - * (with a "'" instead of a "|") to help the user identify which process is - * left. In addition, whenever a preempted call is about to be resumed, a "*" - * is printed instead of a space, so as to show that it is a continuation of a - * previous line. An example of all these cases: + * Print a prefix for a line of output. Possibly print a timestamp first. + * Then, if applicable, print a PID prefix for the given process, or an info + * prefix if no process (NULL) is given. + * + * PIDs are relevant only when multiple processes are traced. As long as there + * are multiple processes, each line is prefixed with the PID of the process. + * As soon as the number of processes has been reduced back to one, one more + * line is prefixed with the PID of the remaining process (with a "'" instead + * of a "|") to help the user identify which process remains. In addition, + * whenever a preempted call is about to be resumed, a "*" is printed instead + * of a space, so as to show that it is a continuation of a previous line. An + * example of all these cases: * * fork() = 3 * 3| Tracing test (pid 3) @@ -191,11 +194,33 @@ output_flush(void) static void put_prefix(struct trace_proc * proc, int resuming) { + struct timeval tv; + struct tm *tm; char prefix[32]; - unsigned int count; + unsigned int off, count; assert(line_off == 0); + off = 0; + + if (timestamps > 0) { + gettimeofday(&tv, NULL); + + tm = gmtime(&tv.tv_sec); + + off = strftime(prefix, sizeof(prefix), "%T", tm); + + if (timestamps > 1) + off += snprintf(&prefix[off], sizeof(prefix) - off, + ".%06u", tv.tv_usec); + + assert(off < sizeof(prefix) - 2); + prefix[off++] = ' '; + prefix[off] = '\0'; + + off = output_write(prefix); + } + count = proc_count(); /* TODO: add a command line option for always printing the pid. */ @@ -212,14 +237,14 @@ put_prefix(struct trace_proc * proc, int resuming) proc->pid, (count > 1) ? '|' : '\'', resuming ? '*' : ' '); - prefix_off = line_off = output_write(prefix); + off += output_write(prefix); last_pid = (proc != NULL ? proc->pid : 0); - } else { + } else assert(!resuming); - prefix_off = 0; - } + prefix_off = off; + line_off += off; /* Remember whether the next line should get prefixed regardless. */ print_pid = (count > 1 || proc == NULL); diff --git a/minix/usr.bin/trace/proto.h b/minix/usr.bin/trace/proto.h index 90333d391..11591edc1 100644 --- a/minix/usr.bin/trace/proto.h +++ b/minix/usr.bin/trace/proto.h @@ -96,6 +96,7 @@ unsigned int proc_count(void); const char *get_signal_name(int sig); /* trace.c */ +extern int timestamps; extern int allnames; extern unsigned int verbose; extern unsigned int valuesonly; diff --git a/minix/usr.bin/trace/trace.1 b/minix/usr.bin/trace/trace.1 index 239fa9710..905d4dafb 100644 --- a/minix/usr.bin/trace/trace.1 +++ b/minix/usr.bin/trace/trace.1 @@ -6,7 +6,7 @@ .Nd print process system calls and signals .Sh SYNOPSIS .Nm -.Op Fl fgNsVv +.Op Fl fgNstVv .Op Fl o Ar file .Op Fl p Ar pid .Op Ar command @@ -58,6 +58,14 @@ preceded by a line showing the process's current stack trace. For signals blocked by the target process, the stack trace may not be meaningful. Stack traces may not be supported on all platforms. +.It Fl t +Print timestamps. +By default, no timestamps are printed. +If this flag is given once, each line will be prefixed by the current time. +If this flag is given twice, the time will also include microseconds. +The printed timestamp corresponds to the time at which printing of the rest of +the line was initiated, which in the case of call resumption may not be the +same as the time that the system call was initiated. .It Fl V Print values only. If this flag is given once, numerical values will be printed instead of diff --git a/minix/usr.bin/trace/trace.c b/minix/usr.bin/trace/trace.c index 32ae37343..0c50caa6a 100644 --- a/minix/usr.bin/trace/trace.c +++ b/minix/usr.bin/trace/trace.c @@ -8,6 +8,7 @@ #include /* Global variables, used only for a subset of the command line options. */ +int timestamps; /* 0 = none, 1 = time w/o usecs, 2 = time w/usecs */ int allnames; /* FALSE = structure field names, TRUE = all names */ unsigned int valuesonly; /* 0 = normal, 1 = no symbols, 2 = no structures */ unsigned int verbose; /* 0 = essentials, 1 = elaborate, 2 = everything */ @@ -444,7 +445,7 @@ static void __dead usage(void) { - (void)fprintf(stderr, "usage: %s [-fgNsVv] [-o file] [-p pid] " + (void)fprintf(stderr, "usage: %s [-fgNstVv] [-o file] [-p pid] " "[command]\n", getprogname()); exit(EXIT_FAILURE); @@ -471,11 +472,12 @@ main(int argc, char * argv[]) grouping = FALSE; output_file = NULL; + timestamps = 0; allnames = FALSE; verbose = 0; valuesonly = 0; - while ((c = getopt(argc, argv, "fgNsVvo:p:")) != -1) { + while ((c = getopt(argc, argv, "fgNstVvo:p:")) != -1) { switch (c) { case 'f': follow_fork = TRUE; @@ -489,6 +491,9 @@ main(int argc, char * argv[]) case 's': show_stack = TRUE; break; + case 't': + timestamps++; + break; case 'V': valuesonly++; break;