Weird truss output
Dan Nelson
dnelson at allantgroup.com
Wed Dec 3 10:56:25 PST 2008
In the last episode (Dec 03), Dan Nelson said:
> It looks like there's some other problem where truss either drops a
> syscall event, or puts some status fields into the wrong thread's
> structure. It seems to happen when two threads call blocking
> syscalls, and when they return, truss gets confused as to which
> thread called which syscall. The read syscall is probably still
> pending, and you're getting the arguments of the syscall that
> returned, printed as if it was the read syscall. When the read call
> completes, you'll probably get an --UNKNOWN SYSCALL-- line, or
> another mismatched syscall output line.
It turns out that was the problem. There was a global structure that
held syscall information. Converting it to a per-thread structure
makes it work much better :) If you're adventurous, try applying the
patch at http://www.evoy.net/FreeBSD/truss.diff , which fixes that
problem plus a bunch of other stuff. If you're not adventurous, try
the following instead, which just fixes the per-thread problem.
Index: i386-fbsd.c
===================================================================
RCS file: /home/ncvs/src/usr.bin/truss/i386-fbsd.c,v
retrieving revision 1.29
diff -u -r1.29 i386-fbsd.c
--- i386-fbsd.c 28 Jul 2007 23:15:04 -0000 1.29
+++ i386-fbsd.c 3 Dec 2008 18:48:23 -0000
@@ -49,6 +49,7 @@
#include <machine/reg.h>
#include <machine/psl.h>
+#include <err.h>
#include <errno.h>
#include <fcntl.h>
#include <signal.h>
@@ -77,29 +78,29 @@
* 'struct syscall' describes the system call; it may be NULL, however,
* if we don't know about this particular system call yet.
*/
-static struct freebsd_syscall {
+struct freebsd_syscall {
struct syscall *sc;
const char *name;
int number;
unsigned long *args;
int nargs; /* number of arguments -- *not* number of words! */
char **s_args; /* the printable arguments */
-} fsc;
+};
/* Clear up and free parts of the fsc structure. */
static __inline void
-clear_fsc(void) {
- if (fsc.args) {
- free(fsc.args);
+clear_fsc(struct freebsd_syscall *fsc) {
+ if (fsc->args) {
+ free(fsc->args);
}
- if (fsc.s_args) {
+ if (fsc->s_args) {
int i;
- for (i = 0; i < fsc.nargs; i++)
- if (fsc.s_args[i])
- free(fsc.s_args[i]);
- free(fsc.s_args);
+ for (i = 0; i < fsc->nargs; i++)
+ if (fsc->s_args[i])
+ free(fsc->s_args[i]);
+ free(fsc->s_args);
}
- memset(&fsc, 0, sizeof(fsc));
+ memset(fsc, 0, sizeof(*fsc));
}
/*
@@ -117,9 +118,20 @@
unsigned int parm_offset;
struct syscall *sc = NULL;
struct ptrace_io_desc iorequest;
+ struct freebsd_syscall *fsc;
+
cpid = trussinfo->curthread->tid;
- clear_fsc();
+ fsc = trussinfo->curthread->fsc;
+ if (fsc == NULL)
+ {
+ fsc = malloc(sizeof(*fsc));
+ if (fsc == NULL)
+ errx(1, "cannot allocate syscall struct");
+ memset(fsc, 0, sizeof(*fsc));
+ trussinfo->curthread->fsc = fsc;
+ } else
+ clear_fsc(fsc);
if (ptrace(PT_GETREGS, cpid, (caddr_t)®s, 0) < 0)
{
@@ -145,17 +157,24 @@
break;
}
- fsc.number = syscall_num;
- fsc.name =
+ fsc->number = syscall_num;
+ fsc->name =
(syscall_num < 0 || syscall_num > nsyscalls) ? NULL : syscallnames[syscall_num];
- if (!fsc.name) {
- fprintf(trussinfo->outfile, "-- UNKNOWN SYSCALL %d --\n", syscall_num);
+ if (!fsc->name) {
+ fprintf(trussinfo->outfile, "-- UNKNOWN SYSCALL %u (0x%08x) --\n", syscall_num, syscall_num);
+ if ((unsigned int)syscall_num > 0x1000) {
+ /* When attaching to a running process, we have a 50-50 chance
+ of attaching to a process waiting in a syscall, which means
+ our first trap is an exit instead of an entry and we're out
+ of synch. Reset our flag */
+ trussinfo->curthread->in_syscall = 0;
+ }
}
- if (fsc.name && (trussinfo->flags & FOLLOWFORKS)
- && ((!strcmp(fsc.name, "fork")
- || !strcmp(fsc.name, "rfork")
- || !strcmp(fsc.name, "vfork"))))
+ if (fsc->name && (trussinfo->flags & FOLLOWFORKS)
+ && ((!strcmp(fsc->name, "fork")
+ || !strcmp(fsc->name, "rfork")
+ || !strcmp(fsc->name, "vfork"))))
{
trussinfo->curthread->in_fork = 1;
}
@@ -163,30 +182,30 @@
if (nargs == 0)
return;
- fsc.args = malloc((1+nargs) * sizeof(unsigned long));
+ fsc->args = malloc((1+nargs) * sizeof(unsigned long));
iorequest.piod_op = PIOD_READ_D;
iorequest.piod_offs = (void *)parm_offset;
- iorequest.piod_addr = fsc.args;
+ iorequest.piod_addr = fsc->args;
iorequest.piod_len = (1+nargs) * sizeof(unsigned long);
ptrace(PT_IO, cpid, (caddr_t)&iorequest, 0);
if (iorequest.piod_len == 0)
return;
- if (fsc.name)
- sc = get_syscall(fsc.name);
+ if (fsc->name)
+ sc = get_syscall(fsc->name);
if (sc) {
- fsc.nargs = sc->nargs;
+ fsc->nargs = sc->nargs;
} else {
#if DEBUG
fprintf(trussinfo->outfile, "unknown syscall %s -- setting args to %d\n",
- fsc.name, nargs);
+ fsc->name, nargs);
#endif
- fsc.nargs = nargs;
+ fsc->nargs = nargs;
}
- fsc.s_args = malloc((1+fsc.nargs) * sizeof(char*));
- memset(fsc.s_args, 0, fsc.nargs * sizeof(char*));
- fsc.sc = sc;
+ fsc->s_args = malloc((1+fsc->nargs) * sizeof(char*));
+ memset(fsc->s_args, 0, fsc->nargs * sizeof(char*));
+ fsc->sc = sc;
/*
* At this point, we set up the system call arguments.
@@ -196,21 +215,21 @@
* passed in *and* out, however.
*/
- if (fsc.name) {
+ if (fsc->name) {
#if DEBUG
- fprintf(stderr, "syscall %s(", fsc.name);
+ fprintf(stderr, "syscall %s(", fsc->name);
#endif
- for (i = 0; i < fsc.nargs; i++) {
+ for (i = 0; i < fsc->nargs; i++) {
#if DEBUG
fprintf(stderr, "0x%x%s",
sc
- ? fsc.args[sc->args[i].offset]
- : fsc.args[i],
- i < (fsc.nargs - 1) ? "," : "");
+ ? fsc->args[sc->args[i].offset]
+ : fsc->args[i],
+ i < (fsc->nargs - 1) ? "," : "");
#endif
if (sc && !(sc->args[i].type & OUT)) {
- fsc.s_args[i] = print_arg(&sc->args[i], fsc.args, 0, trussinfo);
+ fsc->s_args[i] = print_arg(&sc->args[i], fsc->args, 0, trussinfo);
}
}
#if DEBUG
@@ -222,23 +241,23 @@
fprintf(trussinfo->outfile, "\n");
#endif
- if (fsc.name != NULL &&
- (!strcmp(fsc.name, "execve") || !strcmp(fsc.name, "exit"))) {
+ if (fsc->name != NULL &&
+ (!strcmp(fsc->name, "execve") || !strcmp(fsc->name, "exit"))) {
/* XXX
* This could be done in a more general
* manner but it still wouldn't be very pretty.
*/
- if (!strcmp(fsc.name, "execve")) {
+ if (!strcmp(fsc->name, "execve")) {
if ((trussinfo->flags & EXECVEARGS) == 0)
- if (fsc.s_args[1]) {
- free(fsc.s_args[1]);
- fsc.s_args[1] = NULL;
+ if (fsc->s_args[1]) {
+ free(fsc->s_args[1]);
+ fsc->s_args[1] = NULL;
}
if ((trussinfo->flags & EXECVEENVS) == 0)
- if (fsc.s_args[2]) {
- free(fsc.s_args[2]);
- fsc.s_args[2] = NULL;
+ if (fsc->s_args[2]) {
+ free(fsc->s_args[2]);
+ fsc->s_args[2] = NULL;
}
}
@@ -262,9 +281,14 @@
int i;
int errorp;
struct syscall *sc;
+ struct freebsd_syscall *fsc;
- if (fsc.name == NULL)
+ fsc = trussinfo->curthread->fsc;
+ if (fsc == NULL || fsc->name == NULL) {
+ fprintf(trussinfo->outfile, "No syscall?\n");
+ fflush(trussinfo->outfile);
return (-1);
+ }
cpid = trussinfo->curthread->tid;
if (ptrace(PT_GETREGS, cpid, (caddr_t)®s, 0) < 0)
@@ -281,10 +305,10 @@
* stand some significant cleaning.
*/
- sc = fsc.sc;
+ sc = fsc->sc;
if (!sc) {
- for (i = 0; i < fsc.nargs; i++)
- asprintf(&fsc.s_args[i], "0x%lx", fsc.args[i]);
+ for (i = 0; i < fsc->nargs; i++)
+ asprintf(&fsc->s_args[i], "0x%lx", fsc->args[i]);
} else {
/*
* Here, we only look for arguments that have OUT masked in --
@@ -298,10 +322,10 @@
* it may not be valid.
*/
if (errorp)
- asprintf(&temp, "0x%lx", fsc.args[sc->args[i].offset]);
+ asprintf(&temp, "0x%lx", fsc->args[sc->args[i].offset]);
else
- temp = print_arg(&sc->args[i], fsc.args, retval, trussinfo);
- fsc.s_args[i] = temp;
+ temp = print_arg(&sc->args[i], fsc->args, retval, trussinfo);
+ fsc->s_args[i] = temp;
}
}
}
@@ -312,15 +336,15 @@
* The nargs check is so we don't have to do yet another strcmp on every
* syscall.
*/
- if (!errorp && fsc.nargs == 0 && fsc.name && strcmp(fsc.name, "pipe") == 0) {
- fsc.nargs = 1;
- fsc.s_args = malloc((1+fsc.nargs) * sizeof(char*));
- asprintf(&fsc.s_args[0], "[%d,%d]", (int)retval, regs.r_edx);
+ if (!errorp && fsc->nargs == 0 && fsc->name && strcmp(fsc->name, "pipe") == 0) {
+ fsc->nargs = 1;
+ fsc->s_args = malloc((1+fsc->nargs) * sizeof(char*));
+ asprintf(&fsc->s_args[0], "[%d,%d]", (int)retval, regs.r_edx);
retval = 0;
}
- if (fsc.name != NULL &&
- (!strcmp(fsc.name, "execve") || !strcmp(fsc.name, "exit"))) {
+ if (fsc->name != NULL &&
+ (!strcmp(fsc->name, "execve") || !strcmp(fsc->name, "exit"))) {
trussinfo->curthread->in_syscall = 1;
}
@@ -329,8 +353,8 @@
* but that complicates things considerably.
*/
- print_syscall_ret(trussinfo, fsc.name, fsc.nargs, fsc.s_args, errorp, retval);
- clear_fsc();
+ print_syscall_ret(trussinfo, fsc->name, fsc->nargs, fsc->s_args, errorp, retval);
+ clear_fsc(fsc);
return (retval);
}
Index: setup.c
===================================================================
RCS file: /home/ncvs/src/usr.bin/truss/setup.c,v
retrieving revision 1.24
diff -u -r1.24 setup.c
--- setup.c 26 Jun 2007 22:42:37 -0000 1.24
+++ setup.c 3 Dec 2008 18:49:06 -0000
@@ -166,6 +166,7 @@
np->tid = lwpid;
np->in_fork = 0;
np->in_syscall = 0;
+ np->fsc = NULL;
SLIST_INSERT_HEAD(&info->threadlist, np, entries);
info->curthread = np;
}
Index: truss.h
===================================================================
RCS file: /home/ncvs/src/usr.bin/truss/truss.h,v
retrieving revision 1.8
diff -u -r1.8 truss.h
--- truss.h 10 Apr 2007 04:03:34 -0000 1.8
+++ truss.h 3 Dec 2008 18:42:54 -0000
@@ -38,6 +38,7 @@
{
SLIST_ENTRY(threadinfo) entries;
lwpid_t tid;
+ void *fsc;
int in_syscall;
int in_fork;
};
--
Dan Nelson
dnelson at allantgroup.com
More information about the freebsd-stable
mailing list