zfs-patches/0039-Report-duration-and-error-in-mmp_history-entries.patch

   1 From 0000000000000000000000000000000000000000 Mon Sep 17 00:00:00 2001
   2 From: Olaf Faaland <faaland1@llnl.gov>
   3 Date: Thu, 22 Feb 2018 15:34:34 -0800
   4 Subject: [PATCH] Report duration and error in mmp_history entries
   5 MIME-Version: 1.0
   6 Content-Type: text/plain; charset=UTF-8
   7 Content-Transfer-Encoding: 8bit
   8
   9 After an MMP write completes, update the relevant mmp_history entry
  10 with the time between submission and completion, and the error
  11 status of the write.
  12
  13 [faaland1@toss3a zfs]$ cat /proc/spl/kstat/zfs/pool/multihost
  14 39 0 0x01 100 8800 69147946270893 72723903122926
  15 id       txg     timestamp  error  duration   mmp_delay    vdev_guid
  16 10607    1166    1518985089 0      138301     637785455    4882...
  17 10608    1166    1518985089 0      136154     635407747    1151...
  18 10609    1166    1518985089 0      803618560  633048078    9740...
  19 10610    1166    1518985090 0      144826     633048078    4882...
  20 10611    1166    1518985090 0      164527     666187671    1151...
  21
  22 Where duration = gethrtime_in_done_fn - gethrtime_at_submission, and
  23 error = zio->io_error.
  24
  25 Reviewed-by: Giuseppe Di Natale <dinatale2@llnl.gov>
  26 Reviewed-by: Brian Behlendorf <behlendorf1@llnl.gov>
  27 Signed-off-by: Olaf Faaland <faaland1@llnl.gov>
  28 Closes #7190
  29 (cherry picked from commit 2644784f49a6b6be063d54ca0e1662ee6bef7ebd)
  30 Signed-off-by: Fabian Grünbichler <f.gruenbichler@proxmox.com>
  31 ---
  32  include/sys/mmp.h       |  1 +
  33  include/sys/spa.h       |  4 +++-
  34  include/sys/vdev_impl.h |  1 +
  35  module/zfs/mmp.c        | 13 ++++++++++--
  36  module/zfs/spa_stats.c  | 54 ++++++++++++++++++++++++++++++++++++++++---------
  37  5 files changed, 60 insertions(+), 13 deletions(-)
  38
  39 diff --git a/include/sys/mmp.h b/include/sys/mmp.h
  40 index 5b2fea1a6..1ce685f9c 100644
  41 --- a/include/sys/mmp.h
  42 +++ b/include/sys/mmp.h
  43 @@ -42,6 +42,7 @@ typedef struct mmp_thread {
  44         uint64_t        mmp_delay;      /* decaying avg ns between MMP writes */
  45         uberblock_t     mmp_ub;         /* last ub written by sync */
  46         zio_t           *mmp_zio_root;  /* root of mmp write zios */
  47 +       uint64_t        mmp_kstat_id;   /* unique id for next MMP write kstat */
  48  } mmp_thread_t;
  49
  50
  51 diff --git a/include/sys/spa.h b/include/sys/spa.h
  52 index 67235871f..53fa5514a 100644
  53 --- a/include/sys/spa.h
  54 +++ b/include/sys/spa.h
  55 @@ -759,8 +759,10 @@ extern txg_stat_t *spa_txg_history_init_io(spa_t *, uint64_t,
  56      struct dsl_pool *);
  57  extern void spa_txg_history_fini_io(spa_t *, txg_stat_t *);
  58  extern void spa_tx_assign_add_nsecs(spa_t *spa, uint64_t nsecs);
  59 +extern int spa_mmp_history_set(spa_t *spa, uint64_t mmp_kstat_id, int io_error,
  60 +    hrtime_t duration);
  61  extern void spa_mmp_history_add(uint64_t txg, uint64_t timestamp,
  62 -    uint64_t mmp_delay, vdev_t *vd, int label);
  63 +    uint64_t mmp_delay, vdev_t *vd, int label, uint64_t mmp_kstat_id);
  64
  65  /* Pool configuration locks */
  66  extern int spa_config_tryenter(spa_t *spa, int locks, void *tag, krw_t rw);
  67 diff --git a/include/sys/vdev_impl.h b/include/sys/vdev_impl.h
  68 index 4c2e3cd2e..13c495822 100644
  69 --- a/include/sys/vdev_impl.h
  70 +++ b/include/sys/vdev_impl.h
  71 @@ -238,6 +238,7 @@ struct vdev {
  72         vdev_aux_t      vdev_label_aux; /* on-disk aux state            */
  73         uint64_t        vdev_leaf_zap;
  74         hrtime_t        vdev_mmp_pending; /* 0 if write finished        */
  75 +       uint64_t        vdev_mmp_kstat_id;      /* to find kstat entry */
  76
  77         /*
  78          * For DTrace to work in userland (libzpool) context, these fields must
  79 diff --git a/module/zfs/mmp.c b/module/zfs/mmp.c
  80 index d003d79de..ee8e9201b 100644
  81 --- a/module/zfs/mmp.c
  82 +++ b/module/zfs/mmp.c
  83 @@ -135,6 +135,7 @@ mmp_init(spa_t *spa)
  84         mutex_init(&mmp->mmp_thread_lock, NULL, MUTEX_DEFAULT, NULL);
  85         cv_init(&mmp->mmp_thread_cv, NULL, CV_DEFAULT, NULL);
  86         mutex_init(&mmp->mmp_io_lock, NULL, MUTEX_DEFAULT, NULL);
  87 +       mmp->mmp_kstat_id = 1;
  88  }
  89
  90  void
  91 @@ -244,7 +245,8 @@ mmp_write_done(zio_t *zio)
  92         mmp_thread_t *mts = zio->io_private;
  93
  94         mutex_enter(&mts->mmp_io_lock);
  95 -       vd->vdev_mmp_pending = 0;
  96 +       uint64_t mmp_kstat_id = vd->vdev_mmp_kstat_id;
  97 +       hrtime_t mmp_write_duration = gethrtime() - vd->vdev_mmp_pending;
  98
  99         if (zio->io_error)
 100                 goto unlock;
 101 @@ -278,9 +280,15 @@ mmp_write_done(zio_t *zio)
 102         mts->mmp_last_write = gethrtime();
 103
 104  unlock:
 105 +       vd->vdev_mmp_pending = 0;
 106 +       vd->vdev_mmp_kstat_id = 0;
 107 +
 108         mutex_exit(&mts->mmp_io_lock);
 109         spa_config_exit(spa, SCL_STATE, mmp_tag);
 110
 111 +       spa_mmp_history_set(spa, mmp_kstat_id, zio->io_error,
 112 +           mmp_write_duration);
 113 +
 114         abd_free(zio->io_abd);
 115  }
 116
 117 @@ -333,6 +341,7 @@ mmp_write_uberblock(spa_t *spa)
 118         ub->ub_mmp_magic = MMP_MAGIC;
 119         ub->ub_mmp_delay = mmp->mmp_delay;
 120         vd->vdev_mmp_pending = gethrtime();
 121 +       vd->vdev_mmp_kstat_id = mmp->mmp_kstat_id++;
 122
 123         zio_t *zio  = zio_null(mmp->mmp_zio_root, spa, NULL, NULL, NULL, flags);
 124         abd_t *ub_abd = abd_alloc_for_io(VDEV_UBERBLOCK_SIZE(vd), B_TRUE);
 125 @@ -350,7 +359,7 @@ mmp_write_uberblock(spa_t *spa)
 126             flags | ZIO_FLAG_DONT_PROPAGATE);
 127
 128         spa_mmp_history_add(ub->ub_txg, ub->ub_timestamp, ub->ub_mmp_delay, vd,
 129 -           label);
 130 +           label, vd->vdev_mmp_kstat_id);
 131
 132         zio_nowait(zio);
 133  }
 134 diff --git a/module/zfs/spa_stats.c b/module/zfs/spa_stats.c
 135 index 7ca359806..58967e9fc 100644
 136 --- a/module/zfs/spa_stats.c
 137 +++ b/module/zfs/spa_stats.c
 138 @@ -718,21 +718,24 @@ spa_io_history_destroy(spa_t *spa)
 139   */
 140
 141  typedef struct spa_mmp_history {
 142 +       uint64_t        mmp_kstat_id;   /* unique # for updates */
 143         uint64_t        txg;            /* txg of last sync */
 144         uint64_t        timestamp;      /* UTC time of of last sync */
 145         uint64_t        mmp_delay;      /* nanosec since last MMP write */
 146         uint64_t        vdev_guid;      /* unique ID of leaf vdev */
 147         char            *vdev_path;
 148         uint64_t        vdev_label;     /* vdev label */
 149 +       int             io_error;       /* error status of MMP write */
 150 +       hrtime_t        duration;       /* time from submission to completion */
 151         list_node_t     smh_link;
 152  } spa_mmp_history_t;
 153
 154  static int
 155  spa_mmp_history_headers(char *buf, size_t size)
 156  {
 157 -       (void) snprintf(buf, size, "%-10s %-10s %-12s %-24s %-10s %s\n",
 158 -           "txg", "timestamp", "mmp_delay", "vdev_guid", "vdev_label",
 159 -           "vdev_path");
 160 +       (void) snprintf(buf, size, "%-10s %-10s %-10s %-6s %-10s %-12s %-24s "
 161 +           "%-10s %s\n", "id", "txg", "timestamp", "error", "duration",
 162 +           "mmp_delay", "vdev_guid", "vdev_label", "vdev_path");
 163         return (0);
 164  }
 165
 166 @@ -741,11 +744,12 @@ spa_mmp_history_data(char *buf, size_t size, void *data)
 167  {
 168         spa_mmp_history_t *smh = (spa_mmp_history_t *)data;
 169
 170 -       (void) snprintf(buf, size, "%-10llu %-10llu %-12llu %-24llu %-10llu "
 171 -           "%s\n",
 172 -           (u_longlong_t)smh->txg, (u_longlong_t)smh->timestamp,
 173 -           (u_longlong_t)smh->mmp_delay, (u_longlong_t)smh->vdev_guid,
 174 -           (u_longlong_t)smh->vdev_label,
 175 +       (void) snprintf(buf, size, "%-10llu %-10llu %-10llu %-6lld %-10lld "
 176 +           "%-12llu %-24llu %-10llu %s\n",
 177 +           (u_longlong_t)smh->mmp_kstat_id, (u_longlong_t)smh->txg,
 178 +           (u_longlong_t)smh->timestamp, (longlong_t)smh->io_error,
 179 +           (longlong_t)smh->duration, (u_longlong_t)smh->mmp_delay,
 180 +           (u_longlong_t)smh->vdev_guid, (u_longlong_t)smh->vdev_label,
 181             (smh->vdev_path ? smh->vdev_path : "-"));
 182
 183         return (0);
 184 @@ -861,11 +865,40 @@ spa_mmp_history_destroy(spa_t *spa)
 185  }
 186
 187  /*
 188 - * Add a new MMP update to historical record.
 189 + * Set MMP write duration and error status in existing record.
 190 + */
 191 +int
 192 +spa_mmp_history_set(spa_t *spa, uint64_t mmp_kstat_id, int io_error,
 193 +    hrtime_t duration)
 194 +{
 195 +       spa_stats_history_t *ssh = &spa->spa_stats.mmp_history;
 196 +       spa_mmp_history_t *smh;
 197 +       int error = ENOENT;
 198 +
 199 +       if (zfs_multihost_history == 0 && ssh->size == 0)
 200 +               return (0);
 201 +
 202 +       mutex_enter(&ssh->lock);
 203 +       for (smh = list_head(&ssh->list); smh != NULL;
 204 +           smh = list_next(&ssh->list, smh)) {
 205 +               if (smh->mmp_kstat_id == mmp_kstat_id) {
 206 +                       smh->io_error = io_error;
 207 +                       smh->duration = duration;
 208 +                       error = 0;
 209 +                       break;
 210 +               }
 211 +       }
 212 +       mutex_exit(&ssh->lock);
 213 +
 214 +       return (error);
 215 +}
 216 +
 217 +/*
 218 + * Add a new MMP write to historical record.
 219   */
 220  void
 221  spa_mmp_history_add(uint64_t txg, uint64_t timestamp, uint64_t mmp_delay,
 222 -    vdev_t *vd, int label)
 223 +    vdev_t *vd, int label, uint64_t mmp_kstat_id)
 224  {
 225         spa_t *spa = vd->vdev_spa;
 226         spa_stats_history_t *ssh = &spa->spa_stats.mmp_history;
 227 @@ -882,6 +915,7 @@ spa_mmp_history_add(uint64_t txg, uint64_t timestamp, uint64_t mmp_delay,
 228         if (vd->vdev_path)
 229                 smh->vdev_path = strdup(vd->vdev_path);
 230         smh->vdev_label = label;
 231 +       smh->mmp_kstat_id = mmp_kstat_id;
 232
 233         mutex_enter(&ssh->lock);
 234
 235 --
 236 2.14.2
 237