Re: [9front] exportfs: fix debug logging

[Amavect <amavect@gmail.com>]

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

On Fri, 13 Aug 2021 15:11:18 -0400
ori@eigenstate.org wrote:
> Second patch looks ok. First patch -- do we want to fail?
A computer should do what I tell it to do. -d is explicit.

> Also, why not get rid of the debug fd entirely, and either
> syslog() or fprint(2, ...)?
You make a good point. syslog() would be wrong since this is debug
info and not user info (like ssh logins).

Print to stderr is probably the best default for debug info, and can
also be redirected to a file. This obsoletes -f, doesn't care about
creating a debug log file, and rc fails if the file can't be written.

Attached patch is tested with the following:
srvfs -d man /sys/man
srvfs -d man /sys/man >[2]/tmp/dbg
auth/none srvfs -d man /sys/man >[2]/tmp/dbg

auth/none
srvfs -d man /sys/man >[2]/tmp/dbg  # correctly fails

Thanks,
Amavect

[-- Attachment #2.1: Type: text/plain, Size: 310 bytes --]

from postmaster@1ess:
The following attachment had content that we can't
prove to be harmless.  To avoid possible automatic
execution, we changed the content headers.
The original header was:

	Content-Type: text/x-patch
	Content-Transfer-Encoding: 7bit
	Content-Disposition: attachment; filename=exportfs.diff

[-- Attachment #2.2: exportfs.diff.suspect --]
[-- Type: application/octet-stream, Size: 10239 bytes --]

From: amavect <amavect@gmail.com>
Date: Sat, 14 Aug 2021 19:50:23 +0000
Subject: [PATCH] exportfs: make -d log to stderr


exportfs -d logs 9p traffic to /tmp/exportdb.
-f allows writing to a different file.
exportfs silently continues if it doesn't have
permissions to create or write to /tmp/exportdb.
These are poor behaviors.

A better default is to write to stderr, since it
is 9P debug info that is better immediately printed,
and not user info that is better handled by syslog().
As a result, -f is obsolete and thus removed.
Redirect responsibility is now on rc.
As a side effect, rc will fail if it doesn't
have permissions to write.

exportfs(4) is updated to reflect all changes
and with a better Synopsis.
---
diff 2af46e406bbd443ae10025777247798a685afc3c 3b8f235550fedee4c4a42a341e993351a76ecf03
--- a/sys/man/4/exportfs	Thu Aug 12 20:27:17 2021
+++ b/sys/man/4/exportfs	Sat Aug 14 14:50:23 2021
@@ -4,7 +4,23 @@
 .SH SYNOPSIS
 .B exportfs
 [
-.I options
+.B -dsR
+]
+[
+.B -m
+.I msize
+]
+[
+.B -r
+.I root
+]
+[
+.B -P
+.I patternfile
+]
+[
+.B -S
+.I srvfile
 ]
 .PP
 .B srvfs
@@ -39,11 +55,8 @@
 .PP
 The options are:
 .TP
-.B -d -f \fIdbgfile
-Log all 9P traffic to
-.I dbgfile
-(default
-.BR /tmp/exportdb ).
+.B -d
+Log all 9P traffic to stderr.
 .TP
 .B -P \fIpatternfile
 Restrict the set of exported files.
--- a/sys/src/cmd/exportfs/exportfs.c	Thu Aug 12 20:27:17 2021
+++ b/sys/src/cmd/exportfs/exportfs.c	Sat Aug 14 14:50:23 2021
@@ -10,18 +10,16 @@
 void
 usage(void)
 {
-	fprint(2, "usage: %s [-dsR] [-f dbgfile] [-m msize] [-r root] "
-		"[-S srvfile] [-P exclusion-file]\n", argv0);
+	fprint(2, "usage: %s [-dsR] [-m msize] [-r root] "
+		"[-P patternfile] [-S srvfile]\n", argv0);
 	fatal("usage");
 }
 
 void
 main(int argc, char **argv)
 {
-	char *dbfile, *srv, *srvfdfile;
-	int n;
+	char *srv, *srvfdfile;
 
-	dbfile = "/tmp/exportdb";
 	srv = nil;
 	srvfd = -1;
 	srvfdfile = nil;
@@ -31,10 +29,6 @@
 		dbg++;
 		break;
 
-	case 'f':
-		dbfile = EARGF(usage());
-		break;
-
 	case 'm':
 		messagesize = strtoul(EARGF(usage()), nil, 0);
 		break;
@@ -82,13 +76,7 @@
 
 	exclusions();
 
-	if(dbg) {
-		n = create(dbfile, OWRITE|OTRUNC, 0666);
-		dup(n, DFD);
-		close(n);
-	}
-
-	DEBUG(DFD, "exportfs: started\n");
+	DEBUG(2, "exportfs: started\n");
 
 	rfork(RFNOTEG|RFREND);
 
@@ -106,13 +94,13 @@
 			char ebuf[ERRMAX];
 			ebuf[0] = '\0';
 			errstr(ebuf, sizeof ebuf);
-			DEBUG(DFD, "chdir(\"%s\"): %s\n", srv, ebuf);
+			DEBUG(2, "chdir(\"%s\"): %s\n", srv, ebuf);
 			mounterror(ebuf);
 		}
-		DEBUG(DFD, "invoked as server for %s", srv);
+		DEBUG(2, "invoked as server for %s", srv);
 	}
 
-	DEBUG(DFD, "\niniting root\n");
+	DEBUG(2, "\niniting root\n");
 	initroot();
 	io();
 }
--- a/sys/src/cmd/exportfs/exportfs.h	Thu Aug 12 20:27:17 2021
+++ b/sys/src/cmd/exportfs/exportfs.h	Sat Aug 14 14:50:23 2021
@@ -3,7 +3,6 @@
  */
 
 #define DEBUG		if(!dbg){}else fprint
-#define DFD		9
 #define fidhash(s)	fhash[s%FHASHSIZE]
 
 typedef struct Fsrpc Fsrpc;
--- a/sys/src/cmd/exportfs/exportsrv.c	Thu Aug 12 20:27:17 2021
+++ b/sys/src/cmd/exportfs/exportsrv.c	Sat Aug 14 14:50:23 2021
@@ -65,7 +65,7 @@
 		w = m->busy;
 		if(w != nil && w->work.tag == t->work.oldtag) {
 			w->flushtag = t->work.tag;
-			DEBUG(DFD, "\tset flushtag %d\n", t->work.tag);
+			DEBUG(2, "\tset flushtag %d\n", t->work.tag);
 			postnote(PNPROC, m->pid, "flush");
 			unlock(m);
 			putsbuf(t);
@@ -75,7 +75,7 @@
 	}
 
 	reply(&t->work, &rhdr, 0);
-	DEBUG(DFD, "\tflush reply\n");
+	DEBUG(2, "\tflush reply\n");
 	putsbuf(t);
 }
 
@@ -359,7 +359,7 @@
 	}
 
 	path = makepath(f->f, "");
-	DEBUG(DFD, "\tremove: %s\n", path);
+	DEBUG(2, "\tremove: %s\n", path);
 	if(remove(path) < 0) {
 		free(path);
 		errstr(err, sizeof err);
@@ -518,7 +518,7 @@
 		if(p == nil)		/* Swept */
 			break;
 
-		DEBUG(DFD, "\tslave: %d %F\n", m->pid, &p->work);
+		DEBUG(2, "\tslave: %d %F\n", m->pid, &p->work);
 		if(p->flushtag != NOTAG)
 			goto flushme;
 
@@ -629,7 +629,7 @@
 	}
 	
 	path = makepath(f->f, "");
-	DEBUG(DFD, "\topen: %s %d\n", path, work->mode);
+	DEBUG(2, "\topen: %s %d\n", path, work->mode);
 	f->fid = open(path, work->mode);
 	free(path);
 	if(f->fid < 0 || (d = dirfstat(f->fid)) == nil) {
@@ -646,7 +646,7 @@
 			goto Error;
 	}
 
-	DEBUG(DFD, "\topen: fd %d\n", f->fid);
+	DEBUG(2, "\topen: fd %d\n", f->fid);
 	f->mode = work->mode;
 	f->offset = 0;
 	rhdr.iounit = getiounit(f->fid);
@@ -688,7 +688,7 @@
 		reply(work, &rhdr, err);
 		return;
 	}
-	DEBUG(DFD, "\tread: fd=%d %d bytes\n", f->fid, r);
+	DEBUG(2, "\tread: fd=%d %d bytes\n", f->fid, r);
 
 	rhdr.data = data;
 	rhdr.count = r;
@@ -720,7 +720,7 @@
 		return;
 	}
 
-	DEBUG(DFD, "\twrite: %d bytes fd=%d\n", n, f->fid);
+	DEBUG(2, "\twrite: %d bytes fd=%d\n", n, f->fid);
 
 	rhdr.count = n;
 	reply(work, &rhdr, 0);
--- a/sys/src/cmd/exportfs/io.c	Thu Aug 12 20:27:17 2021
+++ b/sys/src/cmd/exportfs/io.c	Sat Aug 14 14:50:23 2021
@@ -49,7 +49,7 @@
 		if(convM2S(r->buf, n, &r->work) != n)
 			fatal("convM2S format error");
 
-		DEBUG(DFD, "%F\n", &r->work);
+		DEBUG(2, "%F\n", &r->work);
 		(fcalls[r->work.type])(r);
 	}
 }
@@ -69,7 +69,7 @@
 	else 
 		t->type = r->type + 1;
 
-	DEBUG(DFD, "\t%F\n", t);
+	DEBUG(2, "\t%F\n", t);
 
 	data = malloc(messagesize);	/* not mallocz; no need to clear */
 	if(data == nil)
@@ -224,7 +224,7 @@
 
 	while(--f->ref == 0){
 		freecnt++;
-		DEBUG(DFD, "free %s\n", f->name);
+		DEBUG(2, "free %s\n", f->name);
 		/* delete from parent */
 		parent = f->parent;
 		if(parent->child == f)
@@ -250,7 +250,7 @@
 	char *path;
 	File *f;
 
-	DEBUG(DFD, "\tfile: 0x%p %s name %s\n", parent, parent->name, name);
+	DEBUG(2, "\tfile: 0x%p %s name %s\n", parent, parent->name, name);
 
 	path = makepath(parent, name);
 	if(patternfile != nil && excludefile(path)){
@@ -429,17 +429,17 @@
 	}
 	path = d->qid.path;
 	while(qidexists(path)){
-		DEBUG(DFD, "collision on %s\n", d->name);
+		DEBUG(2, "collision on %s\n", d->name);
 		/* collision: find a new one */
 		ncollision++;
 		path &= QIDPATH;
 		++newqid;
 		if(newqid >= (1<<16)){
-			DEBUG(DFD, "collision wraparound\n");
+			DEBUG(2, "collision wraparound\n");
 			newqid = 1;
 		}
 		path |= newqid<<48;
-		DEBUG(DFD, "assign qid %.16llux\n", path);
+		DEBUG(2, "assign qid %.16llux\n", path);
 	}
 	qidcnt++;
 	q = emallocz(sizeof(Qidtab));
@@ -472,7 +472,7 @@
 		postnote(PNPROC, m->pid, "kill");
 
 	if(s != nil) {
-		DEBUG(DFD, "%s\n", buf);
+		DEBUG(2, "%s\n", buf);
 		sysfatal("%s", buf);	/* caution: buf could contain '%' */
 	} else
 		exits(nil);
--- a/sys/src/cmd/exportfs/oexportfs.c	Thu Aug 12 20:27:17 2021
+++ b/sys/src/cmd/exportfs/oexportfs.c	Sat Aug 14 14:50:23 2021
@@ -59,7 +59,7 @@
 		strecpy(strrchr(addr, '!'), addr+sizeof(addr), s);
 	}
 
-	DEBUG(DFD, "filter: %s\n", addr);
+	DEBUG(2, "filter: %s\n", addr);
 
 	snprint(buf, sizeof(buf), "%s", cmd);
 	argc = tokenize(buf, argv, nelem(argv)-3);
@@ -256,7 +256,7 @@
 
 	if(dbg) {
 		n = create(dbfile, OWRITE|OTRUNC, 0666);
-		dup(n, DFD);
+		dup(n, 2);
 		close(n);
 	}
 
@@ -265,7 +265,7 @@
 		usage();
 	}
 
-	DEBUG(DFD, "%s: started\n", argv0);
+	DEBUG(2, "%s: started\n", argv0);
 
 	rfork(RFNOTEG|RFREND);
 
@@ -289,10 +289,10 @@
 		if(chdir(srv) < 0) {
 			ebuf[0] = '\0';
 			errstr(ebuf, sizeof ebuf);
-			DEBUG(DFD, "chdir(\"%s\"): %s\n", srv, ebuf);
+			DEBUG(2, "chdir(\"%s\"): %s\n", srv, ebuf);
 			mounterror(ebuf);
 		}
-		DEBUG(DFD, "invoked as server for %s", srv);
+		DEBUG(2, "invoked as server for %s", srv);
 		strncpy(buf, srv, sizeof buf);
 	}
 	else {
@@ -301,22 +301,22 @@
 		if(n < 0) {
 			errstr(buf, sizeof buf);
 			fprint(0, "read(0): %s\n", buf);
-			DEBUG(DFD, "read(0): %s\n", buf);
+			DEBUG(2, "read(0): %s\n", buf);
 			exits(buf);
 		}
 		buf[n] = 0;
 		if(chdir(buf) < 0) {
 			errstr(ebuf, sizeof ebuf);
 			fprint(0, "chdir(%d:\"%s\"): %s\n", n, buf, ebuf);
-			DEBUG(DFD, "chdir(%d:\"%s\"): %s\n", n, buf, ebuf);
+			DEBUG(2, "chdir(%d:\"%s\"): %s\n", n, buf, ebuf);
 			exits(ebuf);
 		}
 	}
 
-	DEBUG(DFD, "\niniting root\n");
+	DEBUG(2, "\niniting root\n");
 	initroot();
 
-	DEBUG(DFD, "%s: %s\n", argv0, buf);
+	DEBUG(2, "%s: %s\n", argv0, buf);
 
 	if(srv == nil && srvfd == -1 && write(0, "OK", 2) != 2)
 		fatal("open ack write");
@@ -436,7 +436,7 @@
 
 		if(convM2S(r->buf, n, &r->work) != n)
 			fatal("convM2S format error");
-		DEBUG(DFD, "%F\n", &r->work);
+		DEBUG(2, "%F\n", &r->work);
 		(fcalls[r->work.type])(r);
 	}
 	io();
--- a/sys/src/cmd/exportfs/pattern.c	Thu Aug 12 20:27:17 2021
+++ b/sys/src/cmd/exportfs/pattern.c	Sat Aug 14 14:50:23 2021
@@ -42,7 +42,7 @@
 				if(include == nil)
 					fatal("out of memory");
 			}
-			DEBUG(DFD, "\tinclude %s\n", line+2);
+			DEBUG(2, "\tinclude %s\n", line+2);
 			include[ni] = regcomp(line+2);
 			include[++ni] = nil;
 			break;
@@ -53,12 +53,12 @@
 				if(exclude == nil)
 					fatal("out of memory");
 			}
-			DEBUG(DFD, "\texclude %s\n", line+2);
+			DEBUG(2, "\texclude %s\n", line+2);
 			exclude[ne] = regcomp(line+2);
 			exclude[++ne] = nil;
 			break;
 		default:
-			DEBUG(DFD, "ignoring pattern %s\n", line);
+			DEBUG(2, "ignoring pattern %s\n", line);
 			break;
 		}
 	}
@@ -76,16 +76,16 @@
 	else
 		p = path+1;
 
-	DEBUG(DFD, "checking %s\n", p);
+	DEBUG(2, "checking %s\n", p);
 	for(re = include; *re != nil; re++){
 		if(regexec(*re, p, nil, 0) != 1){
-			DEBUG(DFD, "excluded+ %s\n", p);
+			DEBUG(2, "excluded+ %s\n", p);
 			return -1;
 		}
 	}
 	for(re = exclude; *re != nil; re++){
 		if(regexec(*re, p, nil, 0) == 1){
-			DEBUG(DFD, "excluded- %s\n", p);
+			DEBUG(2, "excluded- %s\n", p);
 			return -1;
 		}
 	}
@@ -98,7 +98,7 @@
 	int r = 0, m;
 	Dir *d;
 
-	DEBUG(DFD, "\tpreaddir n=%d wo=%lld fo=%lld\n", n, offset, f->offset);
+	DEBUG(2, "\tpreaddir n=%d wo=%lld fo=%lld\n", n, offset, f->offset);
 	if(offset == 0 && f->offset != 0){
 		if(seek(f->fid, 0, 0) != 0)
 			return -1;
@@ -128,9 +128,9 @@
 			free(p);
 		}
 		m = convD2M(d, data, n);
-		DEBUG(DFD, "\t\tconvD2M %d\n", m);
+		DEBUG(2, "\t\tconvD2M %d\n", m);
 		if(m <= BIT16SZ){
-			DEBUG(DFD, "\t\t\tneeded %d\n", GBIT16(data));
+			DEBUG(2, "\t\t\tneeded %d\n", GBIT16(data));
 			/* not enough room for full entry; leave for next time */
 			f->cdir--;
 			return r;