[9fans] recreational programming of an evening

[ron minnich <rminnich@gmail.com>]

[-- Attachment #1: Type: text/plain, Size: 2825 bytes --]

I'm an admirer of acid but never found that I like the truss functions
all that much. I've used acid on just enough semi-working platforms,
where breakpoints don't do what is expected, that truss is not
frequently operational and hence not that useful. Also, it's not that
great for fork. And, I'm not that happy about the need to change the
process' memory image just to do tracing. truss() just feels
unfinished.

I pretty much prefer strace on Unix to what acid can do on Plan 9. It
follows forks nicely, and it shows what's going on. And, it works even
if debugging doesn't. And, and on a lightweight node, I don't have to
drag all the acid bits along.

Now, on Linux, strace is a beast: 256KB binary, needs shared
libraries, and so on. (come to think of it that's small for a GNU
program nowadays ...)

What I want is something that works like this:
echo stop > proc/75/ctl
while (echo startsyscall>/proc/75/ctl) {
		cat /proc/75/truss
		}

(note the undocumented startsyscall verb). You need to see the source,
not the man page :-)

Well, turns out to be trivial to do in Plan 9. I did the work against
9vx, since it's so easy to prototype this stuff. The diff is so small
I just attached it. Russ already had nice pretty-print examples for
tracing system calls so I cribbed them.

Here's the output:

75 [cat] Pread 0x13d7 00000000 0fffdf30 00002000 00002000h= 0x9
75 [cat] Pwrite 0x12ed 00000001 0fffdf30 00000009 00000009h= 0x9
75 [cat] Pread 0x13d7 00000000 0fffdf30 00002000 00002000h= 0xc
75 [cat] Pwrite 0x12ed 00000001 0fffdf30 0000000c 0000000ch= 0xc
75 [cat] Pread 0x13d7 00000000 0fffdf30 00002000 00002000h= 0
75 [cat] Open 0x1410 00006990 00000000 00000014 00000014h= 0x3
75 [cat] Pread 0x13d7 00000003 0fffff00 00000014 00000014h= 0xc
75 [cat] Close 0x143e 00000003 0fffff00 00000014 00000014h= 0
75 [cat] Exits 0x128b 00000000 00000000 00000000 00000000hecho: write
error: process exited

So, voila, we have truss, it took 15 minutes to add this in, in fact
almost as long to write this message as to add it in. And a day to
look at the code and ruminate in the odd free moment how to do it. But
that's why I still like this kernel: I can image how much fun this
would have been in just about any Unix, since I've been through a
similar exercise of this sort frequently on Linux.

I may extend it just a bit to dump stuff like file names, read and
write data, and so on. Not that hard in my view.

Anyway, I'll be doing the same thing in the 9k kernel, but the patch I
just attached should give you a hint if you need this. I think it
would help people trying to find problems in 9vx. And, I bet somebody
out there can do a better job than I did.

Obviously, you need to do a bit more work to catch fork but that's
left to the student.

ron

[-- Attachment #2: x --]
[-- Type: application/octet-stream, Size: 3354 bytes --]

diff -r c7e9b5edb8d4 src/9vx/Makefrag
--- a/src/9vx/Makefrag	Sun Dec 27 09:49:22 2009 -0800
+++ b/src/9vx/Makefrag	Tue Mar 16 21:29:23 2010 -0700
@@ -74,6 +74,7 @@
 		devmnt.o \
 		devproc.o \
 		devpipe.o \
+		devram.o \
 		devroot.o \
 		devsd.o \
 		devsrv.o \
diff -r c7e9b5edb8d4 src/9vx/a/AUTOGEN
--- a/src/9vx/a/AUTOGEN	Sun Dec 27 09:49:22 2009 -0800
+++ b/src/9vx/a/AUTOGEN	Tue Mar 16 21:29:23 2010 -0700
@@ -38,6 +38,7 @@
 /sys/src/9/port/devmnt.c
 /sys/src/9/port/devpipe.c
 /sys/src/9/port/devproc.c
+/sys/src/9/port/devram.c
 /sys/src/9/port/devroot.c
 /sys/src/9/port/devsrv.c
 /sys/src/9/port/devtls.c
diff -r c7e9b5edb8d4 src/9vx/a/devproc.c
--- a/src/9vx/a/devproc.c	Sun Dec 27 09:49:22 2009 -0800
+++ b/src/9vx/a/devproc.c	Tue Mar 16 21:29:23 2010 -0700
@@ -31,6 +31,7 @@
 	Qtext,
 	Qwait,
 	Qprofile,
+	Qtruss,
 };
 
 enum
@@ -84,6 +85,7 @@
 	"text",		{Qtext},	0,			0000,
 	"wait",		{Qwait},	0,			0400,
 	"profile",	{Qprofile},	0,			0400,
+	"truss",	{Qtruss},	0,			0400,
 };
 
 static
@@ -397,6 +399,7 @@
 	case Qwait:
 	case Qregs:
 	case Qfpregs:
+	case Qtruss:
 		nonone(p);
 		break;
 
@@ -706,6 +709,12 @@
 		memmove(a, &up->genbuf[offset], n);
 		return n;
 
+	case Qtruss:
+		if (! p->syscalltrace)
+			return 0;
+		n = readstr(offset, a, n, p->syscalltrace);
+		return n;
+
 	case Qmem:
 		if(offset < USTKTOP)
 			return procctlmemio(p, offset, n, va, 1);
diff -r c7e9b5edb8d4 src/9vx/a/portdat.h
--- a/src/9vx/a/portdat.h	Sun Dec 27 09:49:22 2009 -0800
+++ b/src/9vx/a/portdat.h	Tue Mar 16 21:29:23 2010 -0700
@@ -752,6 +752,9 @@
 	 *  machine specific MMU
 	 */
 	PMMU pmmu;
+	/* syscall trace */
+	char *syscalltrace;
+	
 };
 
 enum
diff -r c7e9b5edb8d4 src/9vx/devtab.c
--- a/src/9vx/devtab.c	Sun Dec 27 09:49:22 2009 -0800
+++ b/src/9vx/devtab.c	Tue Mar 16 21:29:23 2010 -0700
@@ -8,6 +8,7 @@
 extern Dev consdevtab;
 extern Dev rootdevtab;
 extern Dev pipedevtab;
+extern Dev ramdevtab;
 extern Dev ssldevtab;
 extern Dev tlsdevtab;
 extern Dev mousedevtab;
@@ -38,6 +39,7 @@
 	&mousedevtab,
 	&pipedevtab,
 	&procdevtab,
+	&ramdevtab,
 	&srvdevtab,
 	&ssldevtab,
 	&tlsdevtab,
diff -r c7e9b5edb8d4 src/9vx/trap.c
--- a/src/9vx/trap.c	Sun Dec 27 09:49:22 2009 -0800
+++ b/src/9vx/trap.c	Tue Mar 16 21:29:23 2010 -0700
@@ -198,8 +198,18 @@
 	up->dbgreg = ureg;
 
 	if(up->procctl == Proc_tracesyscall){
+		uint32 *sp = (uint32*)(up->pmmu.uzero + ureg->usp);
 		up->procctl = Proc_stopme;
+		if (up->syscalltrace)
+			free(up->syscalltrace);
+		up->syscalltrace = smprint("%d [%s] %s %#ux %08ux %08ux %08ux %08uxh",
+				up->pid, up->text,
+				sysctab[ureg->ax], sp[0], sp[1], sp[2], sp[3]);
 		procctl(up);
+		/* you must have read the string by now. The free above is really not needed */
+		if (up->syscalltrace)
+			free(up->syscalltrace);
+		up->syscalltrace = NULL;
 	}
 
 	scallnr = ureg->ax;
@@ -260,9 +270,19 @@
 
 	if(up->procctl == Proc_tracesyscall){
 		up->procctl = Proc_stopme;
+		if (up->syscalltrace)
+			free(up->syscalltrace);
+		if(ureg->ax == -1)
+			up->syscalltrace = smprint("= %s\n", up->syserrstr);
+		else
+			up->syscalltrace = smprint("= %#ux\n", ureg->ax);
 		s = splhi();
 		procctl(up);
 		splx(s);
+		/* you must have read the string by now. The free above is really not needed */
+		if (up->syscalltrace)
+			free(up->syscalltrace);
+		up->syscalltrace = NULL;
 	}
 
 	up->insyscall = 0;