CA-27472: Add cheap vreq time-to-failure dispersion statistics.

We cannot just dump request timestamps, since the log would explode if
failures occur frequently. Instead, produce some minimum amount of
statistics.

For single, apparently spurious failures (e.g. CA-26804), this may
help making more informed guess on whether we are looking at image
driver issues or the current event and retry logic is to blame.

diff --git a/drivers/Makefile b/drivers/Makefile
index 4487b341144722dc4ca0b0943b6c8d9c1bb33898..a404c85877ad551cb185ca93d23985c5aa2edf79 100644 (file)
--- a/drivers/Makefile
+++ b/drivers/Makefile
@@ -14,7 +14,7 @@ CFLAGS    += -I../include
 CFLAGS    += -D_GNU_SOURCE
 CFLAGS    += -DUSE_NFS_LOCKS
 
-LIBS      += -lrt
+LIBS      += -lrt -lm
 
 # Get gcc to generate the dependencies for us.
 CFLAGS    += -Wp,-MD,.$(@F).d

diff --git a/drivers/tapdisk-vbd-stats.h b/drivers/tapdisk-vbd-stats.h
new file mode 100644 (file)
index 0000000..ee400dd
--- /dev/null
+++ b/drivers/tapdisk-vbd-stats.h
@@ -0,0 +1,81 @@
+/*
+ * Copyright (c) 2009, XenSource Inc.
+ * All rights reserved.
+ *
+ * Redistribution and use in source and binary forms, with or without
+ * modification, are permitted provided that the following conditions are met:
+ *     * Redistributions of source code must retain the above copyright
+ *       notice, this list of conditions and the following disclaimer.
+ *     * Redistributions in binary form must reproduce the above copyright
+ *       notice, this list of conditions and the following disclaimer in the
+ *       documentation and/or other materials provided with the distribution.
+ *     * Neither the name of XenSource Inc. nor the names of its contributors
+ *       may be used to endorse or promote products derived from this software
+ *       without specific prior written permission.
+ *
+ * THIS SOFTWARE IS PROVIDED BY THE COPYRIGHT HOLDERS AND CONTRIBUTORS
+ * "AS IS" AND ANY EXPRESS OR IMPLIED WARRANTIES, INCLUDING, BUT NOT
+ * LIMITED TO, THE IMPLIED WARRANTIES OF MERCHANTABILITY AND FITNESS FOR
+ * A PARTICULAR PURPOSE ARE DISCLAIMED. IN NO EVENT SHALL THE COPYRIGHT OWNER
+ * OR CONTRIBUTORS BE LIABLE FOR ANY DIRECT, INDIRECT, INCIDENTAL, SPECIAL,
+ * EXEMPLARY, OR CONSEQUENTIAL DAMAGES (INCLUDING, BUT NOT LIMITED TO,
+ * PROCUREMENT OF SUBSTITUTE GOODS OR SERVICES; LOSS OF USE, DATA, OR
+ * PROFITS; OR BUSINESS INTERRUPTION) HOWEVER CAUSED AND ON ANY THEORY OF
+ * LIABILITY, WHETHER IN CONTRACT, STRICT LIABILITY, OR TORT (INCLUDING
+ * NEGLIGENCE OR OTHERWISE) ARISING IN ANY WAY OUT OF THE USE OF THIS
+ * SOFTWARE, EVEN IF ADVISED OF THE POSSIBILITY OF SUCH DAMAGE.
+ */
+
+#include <math.h>
+
+/*
+ * Incrementally track mean and standard deviation on sample sequences.
+ */
+
+struct dispersion {
+       int     k;              /* number of samples */
+       float   max, min;
+       float   mean, S;        /* mean/stdev accumulators */
+};
+
+#define  TD_STATS_MEAN(_st) ((_st)->mean)
+#define   TD_STATS_VAR(_st) ((_st)->k > 1 ? (_st)->S / ((_st)->k - 1) : 0)
+#define TD_STATS_STDEV(_st) sqrt(TD_STATS_VAR(_st))
+#define   TD_STATS_MIN(_st) ((_st)->k > 0 ? (_st)->min : 0.0)
+#define   TD_STATS_MAX(_st) ((_st)->k > 0 ? (_st)->max : 0.0)
+
+static inline void
+td_dispersion_init(struct dispersion *st)
+{
+       st->k    = 0;
+       st->min  = INFINITY;
+       st->max  = -INFINITY;
+       st->mean = 0.0;
+       st->S    = 0.0;
+}
+
+static inline void
+td_dispersion_add(struct dispersion *st, float val)
+{
+       float _mean = st->mean;
+
+       ++st->k;
+
+       if (val < st->min)
+               st->min = val;
+
+       if (val > st->max)
+               st->max = val;
+
+       /*
+        * The mean is a simple recurrence:
+        * M(1) := x(1); M(k) := M(k-1) + (x(k) - M(k-1)) / k
+        */
+       st->mean += (val - _mean) / st->k;
+
+       /*
+        * Standard deviation is, uuhm, almost as simple (TAOCP Vol.2 4.2.2).
+        * S(1) := 0; S(k) := S(k-1) + (x(k) - M(k-1)) * (x(k) - M(k))
+        */
+       st->S += (val - _mean) * (val - st->mean);
+}

diff --git a/drivers/tapdisk-vbd.c b/drivers/tapdisk-vbd.c
index 9eada2a39703d5892ede83b9053b7b9ad1c02fd2..8af34f240c4723c6ebb72d245c2bcdef409d9bb4 100644 (file)
--- a/drivers/tapdisk-vbd.c
+++ b/drivers/tapdisk-vbd.c
@@ -92,6 +92,7 @@ tapdisk_vbd_initialize(int rfd, int wfd, uint16_t uuid)
        INIT_LIST_HEAD(&vbd->completed_requests);
        INIT_LIST_HEAD(&vbd->next);
        gettimeofday(&vbd->ts, NULL);
+       td_dispersion_init(&vbd->failure_ttl);
 
        for (i = 0; i < MAX_REQUESTS; i++)
                tapdisk_vbd_initialize_vreq(vbd->request_list + i);
@@ -861,6 +862,10 @@ tapdisk_vbd_shutdown(td_vbd_t *vbd)
                vbd->ts.tv_sec, vbd->ts.tv_usec,
                vbd->errors, vbd->retries, vbd->received, vbd->returned,
                vbd->kicked);
+       DPRINTF("failure cnt: %d ttl min: %.3f max: %.3f avg: %.3f stdev: %.3f\n",
+               vbd->failure_ttl.k,
+               TD_STATS_MIN(&vbd->failure_ttl), TD_STATS_MAX(&vbd->failure_ttl),
+               TD_STATS_MEAN(&vbd->failure_ttl), TD_STATS_STDEV(&vbd->failure_ttl));
 
        tapdisk_vbd_close_vdi(vbd);
        tapdisk_ipc_write(&vbd->ipc, TAPDISK_MESSAGE_CLOSE_RSP);
@@ -1164,6 +1169,20 @@ tapdisk_vbd_callback(void *arg, blkif_response_t *rsp)
        tapdisk_vbd_write_response_to_ring(vbd, rsp);
 }
 
+static void
+tapdisk_vbd_failure_stats_add(td_vbd_t *vbd, td_vbd_request_t *vreq)
+{
+       struct timeval now, delta;
+       float fdelta;
+
+       gettimeofday(&now, NULL);
+       timersub(&now, &vbd->ts, &delta);
+       
+       fdelta = (float)delta.tv_sec + (float)delta.tv_usec / 1000000;
+
+       td_dispersion_add(&vbd->failure_ttl, fdelta);
+}
+
 static void
 tapdisk_vbd_make_response(td_vbd_t *vbd, td_vbd_request_t *vreq)
 {
@@ -1180,8 +1199,10 @@ tapdisk_vbd_make_response(td_vbd_t *vbd, td_vbd_request_t *vreq)
        DBG(TLOG_DBG, "writing req %d, sec 0x%08"PRIx64", res %d to ring\n",
            (int)tmp.id, tmp.sector_number, vreq->status);
 
-       if (rsp->status != BLKIF_RSP_OKAY)
+       if (rsp->status != BLKIF_RSP_OKAY) {
                ERR(-vreq->error, "returning BLKIF_RSP %d", rsp->status);
+               tapdisk_vbd_failure_stats_add(vbd, vreq);
+       }
 
        vbd->returned++;
        vbd->callback(vbd->argument, rsp);

diff --git a/drivers/tapdisk-vbd.h b/drivers/tapdisk-vbd.h
index 5c5096e05e8df014c727c4033b3faede9f36bad3..8bcc97a46ddc58891aa3f7a15b12503848dda29e 100644 (file)
--- a/drivers/tapdisk-vbd.h
+++ b/drivers/tapdisk-vbd.h
@@ -36,6 +36,7 @@
 #include "scheduler.h"
 #include "tapdisk-ipc.h"
 #include "tapdisk-image.h"
+#include "tapdisk-vbd-stats.h"
 
 #define TD_VBD_MAX_RETRIES          100
 #define TD_VBD_RETRY_INTERVAL       1
@@ -120,6 +121,8 @@ struct td_vbd_handle {
        uint64_t                    secs_pending;
        uint64_t                    retries;
        uint64_t                    errors;
+
+       struct dispersion           failure_ttl;
 };
 
 #define tapdisk_vbd_for_each_request(vreq, tmp, list)                  \