Fix strace flow control and data extraction issues
authorBarret Rhoden <brho@cs.berkeley.edu>
Thu, 4 Feb 2016 18:34:11 +0000 (13:34 -0500)
committerBarret Rhoden <brho@cs.berkeley.edu>
Thu, 4 Feb 2016 22:39:26 +0000 (17:39 -0500)
There were a few issues.

- Using qwrite() was causing us to block at a bad time.  Using qiwrite()
  won't block, but it also won't do any flow control.  Instead, we do our
own flow control.  Note that we only check on the trace before the syscall.
If we have a start entry, we should have an exit entry, regardless of the
queue size.

- When we procread(), we were grabbing a reference on the proc.  However,
  if the process already exited, then we'd fail.  This prevented us from
draining the queue after the hangup.

- We drop traces.  Now we report the numbers.  If your console is slow, try
  redirecting to a file (e.g. strace foo 2> trace_file).

Signed-off-by: Barret Rhoden <brho@cs.berkeley.edu>
kern/drivers/dev/proc.c
kern/include/syscall.h
kern/src/syscall.c
tests/strace.c

index b5c39d5..7b10712 100644 (file)
@@ -879,6 +879,16 @@ static long procread(struct chan *c, void *va, long n, int64_t off)
                else
                        return readstr(off, va, n, tpids);
 #endif
+       /* Some shit in proc doesn't need to grab the reference.  For strace, we
+        * already have the chan open, and all we want to do is read the queue,
+        * which exists because of our kref on it. */
+       switch (QID(c->qid)) {
+               case Qstrace:
+                       s = c->aux;
+                       n = qread(s->q, va, n);
+                       return n;
+       }
+
        if ((p = pid2proc(SLOT(c->qid))) == NULL)
                error(ESRCH, "%d: no such process", SLOT(c->qid));
        if (p->pid != PID(c->qid)) {
@@ -1157,15 +1167,6 @@ regread:
                        kfree(wq);
                        return n;
 #endif
-               case Qstrace:
-                       s = c->aux;
-                       /* We need to decref, so that p can get freed while we are blocked
-                        * on the qread.  in proc_free, the strace is released that will
-                        * qhangup that will wake us up. */
-                       kref_put(&p->p_kref);
-                       n = qread(s->q, va, n);
-                       return n;
-
                case Qstatus:{
                                /* the old code grew the stack and was hideous.
                                 * status is not a high frequency operation; just malloc. */
@@ -1519,8 +1520,15 @@ void procctlclosefiles(struct proc *p, int all, int fd)
 static void strace_shutdown(struct kref *a)
 {
        struct strace *strace = container_of(a, struct strace, procs);
-
-       qhangup(strace->q, "No more traces");
+       static const char base_msg[] = "Traced ~%lu syscs, Dropped %lu";
+       size_t msg_len = NUMSIZE64 * 2 + sizeof(base_msg);
+       char *msg = kmalloc(msg_len, 0);
+
+       if (msg)
+               snprintf(msg, msg_len, base_msg, strace->appx_nr_sysc,
+                        atomic_read(&strace->nr_drops));
+       qhangup(strace->q, msg);
+       kfree(msg);
 }
 
 static void strace_release(struct kref *a)
@@ -1555,7 +1563,7 @@ static void procctlreq(struct proc *p, char *va, int n)
        case CMstraceme:
                /* common allocation.  if we inherited, we might have one already */
                if (!p->strace) {
-                       strace = kmalloc(sizeof(*p->strace), KMALLOC_WAIT);
+                       strace = kzmalloc(sizeof(*p->strace), KMALLOC_WAIT);
                        strace->q = qopen(65536, Qdropoverflow|Qcoalesce, NULL, NULL);
                        /* both of these refs are put when the proc is freed.  procs is for
                         * every process that has this p->strace.  users is procs + every
index 8ecdc4f..23a3062 100644 (file)
@@ -43,9 +43,10 @@ struct systrace_record {
 };
 
 struct strace {
-       bool opened;
        bool tracing;
        bool inherit;
+       atomic_t nr_drops;
+       unsigned long appx_nr_sysc;
        struct kref procs; /* when procs goes to zero, q is hung up. */
        struct kref users; /* when users goes to zero, q and struct are freed. */
        struct queue *q;
index 9aec24d..b867291 100644 (file)
@@ -103,13 +103,23 @@ static struct systrace_record *sctrace(struct systrace_record *trace,
        assert(p->strace);
 
        if (!trace) {
+               /* We're using qiwrite, which has no flow control.  We'll do it
+                * manually. */
+               if (qfull(p->strace->q)) {
+                       atomic_inc(&p->strace->nr_drops);
+                       return NULL;
+               }
                // TODO: could we allocb and then write that block?
                // Still, if we're tracing, we take a hit, and this is so
                // much more efficient than strace it's not clear we care.
                trace = kmalloc(SYSTR_BUF_SZ, 0);
 
-               if (!trace)
+               if (!trace) {
+                       atomic_inc(&p->strace->nr_drops);
                        return NULL;
+               }
+               /* Avoiding the atomic op.  We sacrifice accuracy for less overhead. */
+               p->strace->appx_nr_sysc++;
 
                int coreid, vcoreid;
                struct proc *p = current;
@@ -158,7 +168,7 @@ static struct systrace_record *sctrace(struct systrace_record *trace,
        trace->datalen = MIN(sizeof(trace->data), datalen);
        memmove(trace->data, (void *)cp, trace->datalen);
        n = systrace_fill_pretty_buf(trace);
-       qwrite(p->strace->q, trace->pretty_buf, n);
+       qiwrite(p->strace->q, trace->pretty_buf, n);
        return trace;
 }
 
index 1432c89..a76251c 100644 (file)
@@ -83,11 +83,10 @@ void main(int argc, char **argv, char **envp)
        sys_proc_run(pid);
 
        while ((amt = read(fd, buf, sizeof(buf))) > 0) {
-               if (write(1, buf, amt) < amt) {
+               if (write(fileno(stderr), buf, amt) < amt) {
                        fprintf(stderr, "Write to stdout: %r\n");
                        exit(1);
                }
        }
-       if ((amt < 0) && (errno != ESRCH))
-               fprintf(stderr, "Read fd %d for %s: %r\n", fd, p);
+       fprintf(stderr, "strace of PID %d: %r\n", pid);
 }