Add support for displaying thread IDs to truss(1).

- Consolidate duplicate code for printing the metadata at the start of
  each line into a shared function.
- Add an -H option which will log the thread ID of the relevant thread
  for each event.

While here, remove some extraneous calls to clock_gettime() in
print_syscall() and print_syscall_ret().  The caller of print_syscall_ret()
always updates the current thread's "after" time before it is called.

Reviewed by:	kib
MFC after:	1 month
Differential Revision:	https://reviews.freebsd.org/D5363
This commit is contained in:
John Baldwin 2016-02-23 19:56:29 +00:00
parent 9a59fb36b2
commit d70876fd7e
Notes: svn2git 2020-12-20 02:59:44 +00:00
svn path=/head/; revision=295930
6 changed files with 63 additions and 75 deletions

View File

@ -31,6 +31,7 @@
* $FreeBSD$
*/
extern int print_line_prefix(struct trussinfo *);
extern void setup_and_wait(struct trussinfo *, char **);
extern void start_tracing(struct trussinfo *, pid_t);
extern void restore_proc(int);

View File

@ -96,7 +96,7 @@ main(int ac, char **av)
trussinfo->curthread = NULL;
LIST_INIT(&trussinfo->proclist);
init_syscalls();
while ((c = getopt(ac, av, "p:o:facedDs:S")) != -1) {
while ((c = getopt(ac, av, "p:o:facedDs:SH")) != -1) {
switch (c) {
case 'p': /* specified pid */
pid = atoi(optarg);
@ -132,6 +132,9 @@ main(int ac, char **av)
case 'S': /* Don't trace signals */
trussinfo->flags |= NOSIGS;
break;
case 'H':
trussinfo->flags |= DISPLAYTIDS;
break;
default:
usage();
}

View File

@ -439,26 +439,46 @@ exit_syscall(struct trussinfo *info, struct ptrace_lwpinfo *pl)
}
}
int
print_line_prefix(struct trussinfo *info)
{
struct timespec timediff;
struct threadinfo *t;
int len;
len = 0;
t = info->curthread;
if (info->flags & (FOLLOWFORKS | DISPLAYTIDS)) {
if (info->flags & FOLLOWFORKS)
len += fprintf(info->outfile, "%5d", t->proc->pid);
if ((info->flags & (FOLLOWFORKS | DISPLAYTIDS)) ==
(FOLLOWFORKS | DISPLAYTIDS))
len += fprintf(info->outfile, " ");
if (info->flags & DISPLAYTIDS)
len += fprintf(info->outfile, "%6d", t->tid);
len += fprintf(info->outfile, ": ");
}
if (info->flags & ABSOLUTETIMESTAMPS) {
timespecsubt(&t->after, &info->start_time, &timediff);
len += fprintf(info->outfile, "%jd.%09ld ",
(intmax_t)timediff.tv_sec, timediff.tv_nsec);
}
if (info->flags & RELATIVETIMESTAMPS) {
timespecsubt(&t->after, &t->before, &timediff);
len += fprintf(info->outfile, "%jd.%09ld ",
(intmax_t)timediff.tv_sec, timediff.tv_nsec);
}
return (len);
}
static void
report_exit(struct trussinfo *info, siginfo_t *si)
{
struct timespec timediff;
struct threadinfo *t;
if (info->flags & FOLLOWFORKS)
fprintf(info->outfile, "%5d: ", si->si_pid);
clock_gettime(CLOCK_REALTIME, &info->curthread->after);
if (info->flags & ABSOLUTETIMESTAMPS) {
timespecsubt(&info->curthread->after, &info->start_time,
&timediff);
fprintf(info->outfile, "%jd.%09ld ", (intmax_t)timediff.tv_sec,
timediff.tv_nsec);
}
if (info->flags & RELATIVETIMESTAMPS) {
timespecsubt(&info->curthread->after, &info->curthread->before,
&timediff);
fprintf(info->outfile, "%jd.%09ld ", (intmax_t)timediff.tv_sec,
timediff.tv_nsec);
}
t = info->curthread;
clock_gettime(CLOCK_REALTIME, &t->after);
print_line_prefix(info);
if (si->si_code == CLD_EXITED)
fprintf(info->outfile, "process exit, rval = %u\n",
si->si_status);
@ -469,48 +489,26 @@ report_exit(struct trussinfo *info, siginfo_t *si)
}
static void
report_new_child(struct trussinfo *info, pid_t pid)
report_new_child(struct trussinfo *info)
{
struct timespec timediff;
struct threadinfo *t;
clock_gettime(CLOCK_REALTIME, &info->curthread->after);
assert(info->flags & FOLLOWFORKS);
fprintf(info->outfile, "%5d: ", pid);
if (info->flags & ABSOLUTETIMESTAMPS) {
timespecsubt(&info->curthread->after, &info->start_time,
&timediff);
fprintf(info->outfile, "%jd.%09ld ", (intmax_t)timediff.tv_sec,
timediff.tv_nsec);
}
if (info->flags & RELATIVETIMESTAMPS) {
timediff.tv_sec = 0;
timediff.tv_nsec = 0;
fprintf(info->outfile, "%jd.%09ld ", (intmax_t)timediff.tv_sec,
timediff.tv_nsec);
}
t = info->curthread;
clock_gettime(CLOCK_REALTIME, &t->after);
t->before = t->after;
print_line_prefix(info);
fprintf(info->outfile, "<new process>\n");
}
static void
report_signal(struct trussinfo *info, siginfo_t *si)
{
struct timespec timediff;
struct threadinfo *t;
char *signame;
if (info->flags & FOLLOWFORKS)
fprintf(info->outfile, "%5d: ", si->si_pid);
if (info->flags & ABSOLUTETIMESTAMPS) {
timespecsubt(&info->curthread->after, &info->start_time,
&timediff);
fprintf(info->outfile, "%jd.%09ld ", (intmax_t)timediff.tv_sec,
timediff.tv_nsec);
}
if (info->flags & RELATIVETIMESTAMPS) {
timespecsubt(&info->curthread->after, &info->curthread->before,
&timediff);
fprintf(info->outfile, "%jd.%09ld ", (intmax_t)timediff.tv_sec,
timediff.tv_nsec);
}
t = info->curthread;
clock_gettime(CLOCK_REALTIME, &t->after);
print_line_prefix(info);
signame = strsig(si->si_status);
fprintf(info->outfile, "SIGNAL %u (%s)\n", si->si_status,
signame == NULL ? "?" : signame);
@ -572,7 +570,7 @@ eventloop(struct trussinfo *info)
pending_signal = 0;
} else if (pl.pl_flags & PL_FLAG_CHILD) {
if ((info->flags & COUNTONLY) == 0)
report_new_child(info, si.si_pid);
report_new_child(info);
pending_signal = 0;
} else {
if ((info->flags & NOSIGS) == 0)

View File

@ -2005,38 +2005,18 @@ print_arg(struct syscall_args *sc, unsigned long *args, long *retval,
void
print_syscall(struct trussinfo *trussinfo)
{
struct timespec timediff;
struct threadinfo *t;
const char *name;
char **s_args;
int i, len, nargs;
len = 0;
t = trussinfo->curthread;
if (trussinfo->flags & FOLLOWFORKS)
len += fprintf(trussinfo->outfile, "%5d: ",
t->proc->pid);
name = t->cs.name;
nargs = t->cs.nargs;
s_args = t->cs.s_args;
if (name != NULL && (strcmp(name, "execve") == 0 ||
strcmp(name, "exit") == 0)) {
clock_gettime(CLOCK_REALTIME, &t->after);
}
if (trussinfo->flags & ABSOLUTETIMESTAMPS) {
timespecsubt(&t->after, &trussinfo->start_time, &timediff);
len += fprintf(trussinfo->outfile, "%jd.%09ld ",
(intmax_t)timediff.tv_sec, timediff.tv_nsec);
}
if (trussinfo->flags & RELATIVETIMESTAMPS) {
timespecsubt(&t->after, &t->before, &timediff);
len += fprintf(trussinfo->outfile, "%jd.%09ld ",
(intmax_t)timediff.tv_sec, timediff.tv_nsec);
}
len = print_line_prefix(trussinfo);
len += fprintf(trussinfo->outfile, "%s(", name);
for (i = 0; i < nargs; i++) {
@ -2063,7 +2043,6 @@ print_syscall_ret(struct trussinfo *trussinfo, int errorp, long *retval)
t = trussinfo->curthread;
sc = t->cs.sc;
if (trussinfo->flags & COUNTONLY) {
clock_gettime(CLOCK_REALTIME, &t->after);
timespecsubt(&t->after, &t->before, &timediff);
timespecadd(&sc->time, &timediff, &sc->time);
sc->ncalls++;

View File

@ -1,6 +1,6 @@
.\" $FreeBSD$
.\"
.Dd October 9, 2015
.Dd February 23, 2016
.Dt TRUSS 1
.Os
.Sh NAME
@ -8,12 +8,12 @@
.Nd trace system calls
.Sh SYNOPSIS
.Nm
.Op Fl facedDS
.Op Fl facedDHS
.Op Fl o Ar file
.Op Fl s Ar strsize
.Fl p Ar pid
.Nm
.Op Fl facedDS
.Op Fl facedDHS
.Op Fl o Ar file
.Op Fl s Ar strsize
.Ar command Op Ar args
@ -32,6 +32,10 @@ Trace descendants of the original traced process created by
.Xr fork 2 ,
.Xr vfork 2 ,
etc.
To distinguish events between processes,
the process ID
.Pq PID
of the process is included in the output of each event.
.It Fl a
Show the argument strings that are passed in each
.Xr execve 2
@ -52,6 +56,8 @@ since the trace was started.
.It Fl D
Include timestamps in the output showing the time elapsed
since the last recorded event.
.It Fl H
Include the thread ID of in the output of each event.
.It Fl S
Do not display information about signals received by the process.
(Normally,

View File

@ -35,6 +35,7 @@
#define EXECVEARGS 0x00000010
#define EXECVEENVS 0x00000020
#define COUNTONLY 0x00000040
#define DISPLAYTIDS 0x00000080
struct procinfo;
struct trussinfo;