perf: Fix stream corruption issues
authorBarret Rhoden <brho@cs.berkeley.edu>
Fri, 3 Jun 2016 14:58:19 +0000 (10:58 -0400)
committerBarret Rhoden <brho@cs.berkeley.edu>
Thu, 16 Jun 2016 16:20:31 +0000 (12:20 -0400)
Under heavy load, e.g. perf record -c 1000 /bin/hello (sampling every 1000
unhalted cycles), the stream would get corrupted.  This would appear as an
"Unknown record" or ridiculous sizes/types.

I'm not 100%, but it looks like the profiler_queue was getting broken up
under some circumstances.  The main culprit was probably that when a core
pushed a block into the queue, it would then do its homebrewed overflow
management.  It would rip the *first* block off the queue, instead of just
dropping the new block.  If for some reason we drained only part of that
block, then we just busted the stream.

This situation could happen if the profiler is being read (qread) at the
same time as samples are created.  Say we looked, saw size = 10, then
someone else came in, added a block, and removed the first block.  Now size
= 12.  We read 10, then that last block is split to 2.  Later on, *that*
block gets removed.  Now the stream is broken.

This commit is a 100% fix - there's another bug where the commit stream
and profiler_queue was getting messed with that I'll fix shortly.

Signed-off-by: Barret Rhoden <brho@cs.berkeley.edu>
kern/drivers/dev/kprof.c
kern/src/profiler.c

index 0d66793..453e195 100644 (file)
@@ -166,18 +166,22 @@ static void kprof_start_profiler(void)
 static void kprof_fetch_profiler_data(void)
 {
        size_t psize = kprof.psize + profiler_size();
+       size_t read_amt;
        char *ndata = krealloc(kprof.pdata, psize, MEM_WAIT);
 
        if (!ndata)
                error(ENOMEM, ERROR_FIXME);
        kprof.pdata = ndata;
+       /* psize includes a snapshot of the profiler's size.  It might grow in the
+        * meantime, but we'll only ever grab as much as we saw originally.  This is
+        * fine.  The important thing is that we only grab contiguous records. */
        while (kprof.psize < psize) {
-               size_t csize = profiler_read(kprof.pdata + kprof.psize,
-                                            psize - kprof.psize);
-
-               if (csize == 0)
-                       break;
-               kprof.psize += csize;
+               read_amt = profiler_read(kprof.pdata + kprof.psize,
+                                        psize - kprof.psize);
+               /* We are the only reader - we must always get whatever was in the
+                * queue. */
+               assert(read_amt);
+               kprof.psize += read_amt;
        }
 }
 
index 2d54af8..1559f40 100644 (file)
@@ -34,7 +34,7 @@ struct profiler_cpu_context {
        struct block *block;
        int cpu;
        int tracing;
-       size_t dropped_data_size;
+       size_t dropped_data_cnt;
 };
 
 static int profiler_queue_limit = 64 * 1024 * 1024;
@@ -64,18 +64,12 @@ static inline char *vb_encode_uint64(char *data, uint64_t n)
 static struct block *profiler_buffer_write(struct profiler_cpu_context *cpu_buf,
                                            struct block *b)
 {
+       /* qpass will drop b if the queue is over its limit.  we're willing to lose
+        * traces, but we won't lose 'control' events, such as MMAP and PID. */
        if (b) {
-               qibwrite(profiler_queue, b);
-
-               if (qlen(profiler_queue) > profiler_queue_limit) {
-                       b = qget(profiler_queue);
-                       if (likely(b)) {
-                               cpu_buf->dropped_data_size += BLEN(b);
-                               freeb(b);
-                       }
-               }
+               if (qpass(profiler_queue, b) < 0)
+                       cpu_buf->dropped_data_cnt++;
        }
-
        return block_alloc(profiler_cpu_buffer_size, MEM_ATOMIC);
 }
 
@@ -268,6 +262,14 @@ static void alloc_cpu_buffers(void)
 {
        ERRSTACK(1);
 
+       /* It is very important that we enqueue and dequeue entire records at once.
+        * If we leave partial records, the entire stream will be corrupt.  Our
+        * reader does its best to make sure it has room for complete records
+        * (checks qlen()).
+        *
+        * If we ever get corrupt streams, try making this a Qmsg.  Though it
+        * doesn't help every situation - we have issues with writes greater than
+        * Maxatomic regardless. */
        profiler_queue = qopen(profiler_queue_limit, 0, NULL, NULL);
        if (!profiler_queue)
                error(ENOMEM, ERROR_FIXME);
@@ -276,8 +278,6 @@ static void alloc_cpu_buffers(void)
                nexterror();
        }
 
-       qdropoverflow(profiler_queue, TRUE);
-
        profiler_percpu_ctx =
            kzmalloc(sizeof(*profiler_percpu_ctx) * num_cores, MEM_WAIT);