module/zfs/spa_history.c

   1 /*
   2  * CDDL HEADER START
   3  *
   4  * The contents of this file are subject to the terms of the
   5  * Common Development and Distribution License (the "License").
   6  * You may not use this file except in compliance with the License.
   7  *
   8  * You can obtain a copy of the license at usr/src/OPENSOLARIS.LICENSE
   9  * or http://www.opensolaris.org/os/licensing.
  10  * See the License for the specific language governing permissions
  11  * and limitations under the License.
  12  *
  13  * When distributing Covered Code, include this CDDL HEADER in each
  14  * file and include the License file at usr/src/OPENSOLARIS.LICENSE.
  15  * If applicable, add the following below this CDDL HEADER, with the
  16  * fields enclosed by brackets "[]" replaced with your own identifying
  17  * information: Portions Copyright [yyyy] [name of copyright owner]
  18  *
  19  * CDDL HEADER END
  20  */
  21
  22 /*
  23  * Copyright (c) 2006, 2010, Oracle and/or its affiliates. All rights reserved.
  24  * Copyright (c) 2011 by Delphix. All rights reserved.
  25  */
  26
  27 #include <sys/spa.h>
  28 #include <sys/spa_impl.h>
  29 #include <sys/zap.h>
  30 #include <sys/dsl_synctask.h>
  31 #include <sys/dmu_tx.h>
  32 #include <sys/dmu_objset.h>
  33 #include <sys/utsname.h>
  34 #include <sys/cmn_err.h>
  35 #include <sys/sunddi.h>
  36 #include "zfs_comutil.h"
  37 #ifdef _KERNEL
  38 #include <sys/zone.h>
  39 #endif
  40
  41 /*
  42  * Routines to manage the on-disk history log.
  43  *
  44  * The history log is stored as a dmu object containing
  45  * <packed record length, record nvlist> tuples.
  46  *
  47  * Where "record nvlist" is a nvlist containing uint64_ts and strings, and
  48  * "packed record length" is the packed length of the "record nvlist" stored
  49  * as a little endian uint64_t.
  50  *
  51  * The log is implemented as a ring buffer, though the original creation
  52  * of the pool ('zpool create') is never overwritten.
  53  *
  54  * The history log is tracked as object 'spa_t::spa_history'.  The bonus buffer
  55  * of 'spa_history' stores the offsets for logging/retrieving history as
  56  * 'spa_history_phys_t'.  'sh_pool_create_len' is the ending offset in bytes of
  57  * where the 'zpool create' record is stored.  This allows us to never
  58  * overwrite the original creation of the pool.  'sh_phys_max_off' is the
  59  * physical ending offset in bytes of the log.  This tells you the length of
  60  * the buffer. 'sh_eof' is the logical EOF (in bytes).  Whenever a record
  61  * is added, 'sh_eof' is incremented by the the size of the record.
  62  * 'sh_eof' is never decremented.  'sh_bof' is the logical BOF (in bytes).
  63  * This is where the consumer should start reading from after reading in
  64  * the 'zpool create' portion of the log.
  65  *
  66  * 'sh_records_lost' keeps track of how many records have been overwritten
  67  * and permanently lost.
  68  */
  69
  70 /* convert a logical offset to physical */
  71 static uint64_t
  72 spa_history_log_to_phys(uint64_t log_off, spa_history_phys_t *shpp)
  73 {
  74         uint64_t phys_len;
  75
  76         phys_len = shpp->sh_phys_max_off - shpp->sh_pool_create_len;
  77         return ((log_off - shpp->sh_pool_create_len) % phys_len
  78             + shpp->sh_pool_create_len);
  79 }
  80
  81 void
  82 spa_history_create_obj(spa_t *spa, dmu_tx_t *tx)
  83 {
  84         dmu_buf_t *dbp;
  85         spa_history_phys_t *shpp;
  86         objset_t *mos = spa->spa_meta_objset;
  87
  88         ASSERT(spa->spa_history == 0);
  89         spa->spa_history = dmu_object_alloc(mos, DMU_OT_SPA_HISTORY,
  90             SPA_MAXBLOCKSIZE, DMU_OT_SPA_HISTORY_OFFSETS,
  91             sizeof (spa_history_phys_t), tx);
  92
  93         VERIFY(zap_add(mos, DMU_POOL_DIRECTORY_OBJECT,
  94             DMU_POOL_HISTORY, sizeof (uint64_t), 1,
  95             &spa->spa_history, tx) == 0);
  96
  97         VERIFY(0 == dmu_bonus_hold(mos, spa->spa_history, FTAG, &dbp));
  98         ASSERT(dbp->db_size >= sizeof (spa_history_phys_t));
  99
 100         shpp = dbp->db_data;
 101         dmu_buf_will_dirty(dbp, tx);
 102
 103         /*
 104          * Figure out maximum size of history log.  We set it at
 105          * 0.1% of pool size, with a max of 1G and min of 128KB.
 106          */
 107         shpp->sh_phys_max_off =
 108             metaslab_class_get_dspace(spa_normal_class(spa)) / 1000;
 109         shpp->sh_phys_max_off = MIN(shpp->sh_phys_max_off, 1<<30);
 110         shpp->sh_phys_max_off = MAX(shpp->sh_phys_max_off, 128<<10);
 111
 112         dmu_buf_rele(dbp, FTAG);
 113 }
 114
 115 /*
 116  * Change 'sh_bof' to the beginning of the next record.
 117  */
 118 static int
 119 spa_history_advance_bof(spa_t *spa, spa_history_phys_t *shpp)
 120 {
 121         objset_t *mos = spa->spa_meta_objset;
 122         uint64_t firstread, reclen, phys_bof;
 123         char buf[sizeof (reclen)];
 124         int err;
 125
 126         phys_bof = spa_history_log_to_phys(shpp->sh_bof, shpp);
 127         firstread = MIN(sizeof (reclen), shpp->sh_phys_max_off - phys_bof);
 128
 129         if ((err = dmu_read(mos, spa->spa_history, phys_bof, firstread,
 130             buf, DMU_READ_PREFETCH)) != 0)
 131                 return (err);
 132         if (firstread != sizeof (reclen)) {
 133                 if ((err = dmu_read(mos, spa->spa_history,
 134                     shpp->sh_pool_create_len, sizeof (reclen) - firstread,
 135                     buf + firstread, DMU_READ_PREFETCH)) != 0)
 136                         return (err);
 137         }
 138
 139         reclen = LE_64(*((uint64_t *)buf));
 140         shpp->sh_bof += reclen + sizeof (reclen);
 141         shpp->sh_records_lost++;
 142         return (0);
 143 }
 144
 145 static int
 146 spa_history_write(spa_t *spa, void *buf, uint64_t len, spa_history_phys_t *shpp,
 147     dmu_tx_t *tx)
 148 {
 149         uint64_t firstwrite, phys_eof;
 150         objset_t *mos = spa->spa_meta_objset;
 151         int err;
 152
 153         ASSERT(MUTEX_HELD(&spa->spa_history_lock));
 154
 155         /* see if we need to reset logical BOF */
 156         while (shpp->sh_phys_max_off - shpp->sh_pool_create_len -
 157             (shpp->sh_eof - shpp->sh_bof) <= len) {
 158                 if ((err = spa_history_advance_bof(spa, shpp)) != 0) {
 159                         return (err);
 160                 }
 161         }
 162
 163         phys_eof = spa_history_log_to_phys(shpp->sh_eof, shpp);
 164         firstwrite = MIN(len, shpp->sh_phys_max_off - phys_eof);
 165         shpp->sh_eof += len;
 166         dmu_write(mos, spa->spa_history, phys_eof, firstwrite, buf, tx);
 167
 168         len -= firstwrite;
 169         if (len > 0) {
 170                 /* write out the rest at the beginning of physical file */
 171                 dmu_write(mos, spa->spa_history, shpp->sh_pool_create_len,
 172                     len, (char *)buf + firstwrite, tx);
 173         }
 174
 175         return (0);
 176 }
 177
 178 static char *
 179 spa_history_zone(void)
 180 {
 181 #ifdef _KERNEL
 182 #ifdef HAVE_SPL
 183         return ("linux");
 184 #else
 185         return (curproc->p_zone->zone_name);
 186 #endif
 187 #else
 188         return ("global");
 189 #endif
 190 }
 191
 192 /*
 193  * Write out a history event.
 194  */
 195 /*ARGSUSED*/
 196 static void
 197 spa_history_log_sync(void *arg1, void *arg2, dmu_tx_t *tx)
 198 {
 199         spa_t           *spa = arg1;
 200         history_arg_t   *hap = arg2;
 201         const char      *history_str = hap->ha_history_str;
 202         objset_t        *mos = spa->spa_meta_objset;
 203         dmu_buf_t       *dbp;
 204         spa_history_phys_t *shpp;
 205         size_t          reclen;
 206         uint64_t        le_len;
 207         nvlist_t        *nvrecord;
 208         char            *record_packed = NULL;
 209         int             ret;
 210
 211         /*
 212          * If we have an older pool that doesn't have a command
 213          * history object, create it now.
 214          */
 215         mutex_enter(&spa->spa_history_lock);
 216         if (!spa->spa_history)
 217                 spa_history_create_obj(spa, tx);
 218         mutex_exit(&spa->spa_history_lock);
 219
 220         /*
 221          * Get the offset of where we need to write via the bonus buffer.
 222          * Update the offset when the write completes.
 223          */
 224         VERIFY(0 == dmu_bonus_hold(mos, spa->spa_history, FTAG, &dbp));
 225         shpp = dbp->db_data;
 226
 227         dmu_buf_will_dirty(dbp, tx);
 228
 229 #ifdef ZFS_DEBUG
 230         {
 231                 dmu_object_info_t doi;
 232                 dmu_object_info_from_db(dbp, &doi);
 233                 ASSERT3U(doi.doi_bonus_type, ==, DMU_OT_SPA_HISTORY_OFFSETS);
 234         }
 235 #endif
 236
 237         VERIFY(nvlist_alloc(&nvrecord, NV_UNIQUE_NAME, KM_PUSHPAGE) == 0);
 238         VERIFY(nvlist_add_uint64(nvrecord, ZPOOL_HIST_TIME,
 239             gethrestime_sec()) == 0);
 240         VERIFY(nvlist_add_uint64(nvrecord, ZPOOL_HIST_WHO, hap->ha_uid) == 0);
 241         if (hap->ha_zone != NULL)
 242                 VERIFY(nvlist_add_string(nvrecord, ZPOOL_HIST_ZONE,
 243                     hap->ha_zone) == 0);
 244 #ifdef _KERNEL
 245         VERIFY(nvlist_add_string(nvrecord, ZPOOL_HIST_HOST,
 246             utsname.nodename) == 0);
 247 #endif
 248         if (hap->ha_log_type == LOG_CMD_POOL_CREATE ||
 249             hap->ha_log_type == LOG_CMD_NORMAL) {
 250                 VERIFY(nvlist_add_string(nvrecord, ZPOOL_HIST_CMD,
 251                     history_str) == 0);
 252
 253                 zfs_dbgmsg("command: %s", history_str);
 254         } else {
 255                 VERIFY(nvlist_add_uint64(nvrecord, ZPOOL_HIST_INT_EVENT,
 256                     hap->ha_event) == 0);
 257                 VERIFY(nvlist_add_uint64(nvrecord, ZPOOL_HIST_TXG,
 258                     tx->tx_txg) == 0);
 259                 VERIFY(nvlist_add_string(nvrecord, ZPOOL_HIST_INT_STR,
 260                     history_str) == 0);
 261
 262                 zfs_dbgmsg("internal %s pool:%s txg:%llu %s",
 263                     zfs_history_event_names[hap->ha_event], spa_name(spa),
 264                     (longlong_t)tx->tx_txg, history_str);
 265
 266         }
 267
 268         VERIFY(nvlist_size(nvrecord, &reclen, NV_ENCODE_XDR) == 0);
 269         record_packed = kmem_alloc(reclen, KM_PUSHPAGE);
 270
 271         VERIFY(nvlist_pack(nvrecord, &record_packed, &reclen,
 272             NV_ENCODE_XDR, KM_PUSHPAGE) == 0);
 273
 274         mutex_enter(&spa->spa_history_lock);
 275         if (hap->ha_log_type == LOG_CMD_POOL_CREATE)
 276                 VERIFY(shpp->sh_eof == shpp->sh_pool_create_len);
 277
 278         /* write out the packed length as little endian */
 279         le_len = LE_64((uint64_t)reclen);
 280         ret = spa_history_write(spa, &le_len, sizeof (le_len), shpp, tx);
 281         if (!ret)
 282                 ret = spa_history_write(spa, record_packed, reclen, shpp, tx);
 283
 284         if (!ret && hap->ha_log_type == LOG_CMD_POOL_CREATE) {
 285                 shpp->sh_pool_create_len += sizeof (le_len) + reclen;
 286                 shpp->sh_bof = shpp->sh_pool_create_len;
 287         }
 288
 289         mutex_exit(&spa->spa_history_lock);
 290         nvlist_free(nvrecord);
 291         kmem_free(record_packed, reclen);
 292         dmu_buf_rele(dbp, FTAG);
 293
 294         strfree(hap->ha_history_str);
 295         if (hap->ha_zone != NULL)
 296                 strfree(hap->ha_zone);
 297         kmem_free(hap, sizeof (history_arg_t));
 298 }
 299
 300 /*
 301  * Write out a history event.
 302  */
 303 int
 304 spa_history_log(spa_t *spa, const char *history_str, history_log_type_t what)
 305 {
 306         history_arg_t *ha;
 307         int err = 0;
 308         dmu_tx_t *tx;
 309
 310         ASSERT(what != LOG_INTERNAL);
 311
 312         tx = dmu_tx_create_dd(spa_get_dsl(spa)->dp_mos_dir);
 313         err = dmu_tx_assign(tx, TXG_WAIT);
 314         if (err) {
 315                 dmu_tx_abort(tx);
 316                 return (err);
 317         }
 318
 319         ha = kmem_alloc(sizeof (history_arg_t), KM_PUSHPAGE);
 320         ha->ha_history_str = strdup(history_str);
 321         ha->ha_zone = strdup(spa_history_zone());
 322         ha->ha_log_type = what;
 323         ha->ha_uid = crgetuid(CRED());
 324
 325         /* Kick this off asynchronously; errors are ignored. */
 326         dsl_sync_task_do_nowait(spa_get_dsl(spa), NULL,
 327             spa_history_log_sync, spa, ha, 0, tx);
 328         dmu_tx_commit(tx);
 329
 330         /* spa_history_log_sync will free ha and strings */
 331         return (err);
 332 }
 333
 334 /*
 335  * Read out the command history.
 336  */
 337 int
 338 spa_history_get(spa_t *spa, uint64_t *offp, uint64_t *len, char *buf)
 339 {
 340         objset_t *mos = spa->spa_meta_objset;
 341         dmu_buf_t *dbp;
 342         uint64_t read_len, phys_read_off, phys_eof;
 343         uint64_t leftover = 0;
 344         spa_history_phys_t *shpp;
 345         int err;
 346
 347         /*
 348          * If the command history  doesn't exist (older pool),
 349          * that's ok, just return ENOENT.
 350          */
 351         if (!spa->spa_history)
 352                 return (ENOENT);
 353
 354         /*
 355          * The history is logged asynchronously, so when they request
 356          * the first chunk of history, make sure everything has been
 357          * synced to disk so that we get it.
 358          */
 359         if (*offp == 0 && spa_writeable(spa))
 360                 txg_wait_synced(spa_get_dsl(spa), 0);
 361
 362         if ((err = dmu_bonus_hold(mos, spa->spa_history, FTAG, &dbp)) != 0)
 363                 return (err);
 364         shpp = dbp->db_data;
 365
 366 #ifdef ZFS_DEBUG
 367         {
 368                 dmu_object_info_t doi;
 369                 dmu_object_info_from_db(dbp, &doi);
 370                 ASSERT3U(doi.doi_bonus_type, ==, DMU_OT_SPA_HISTORY_OFFSETS);
 371         }
 372 #endif
 373
 374         mutex_enter(&spa->spa_history_lock);
 375         phys_eof = spa_history_log_to_phys(shpp->sh_eof, shpp);
 376
 377         if (*offp < shpp->sh_pool_create_len) {
 378                 /* read in just the zpool create history */
 379                 phys_read_off = *offp;
 380                 read_len = MIN(*len, shpp->sh_pool_create_len -
 381                     phys_read_off);
 382         } else {
 383                 /*
 384                  * Need to reset passed in offset to BOF if the passed in
 385                  * offset has since been overwritten.
 386                  */
 387                 *offp = MAX(*offp, shpp->sh_bof);
 388                 phys_read_off = spa_history_log_to_phys(*offp, shpp);
 389
 390                 /*
 391                  * Read up to the minimum of what the user passed down or
 392                  * the EOF (physical or logical).  If we hit physical EOF,
 393                  * use 'leftover' to read from the physical BOF.
 394                  */
 395                 if (phys_read_off <= phys_eof) {
 396                         read_len = MIN(*len, phys_eof - phys_read_off);
 397                 } else {
 398                         read_len = MIN(*len,
 399                             shpp->sh_phys_max_off - phys_read_off);
 400                         if (phys_read_off + *len > shpp->sh_phys_max_off) {
 401                                 leftover = MIN(*len - read_len,
 402                                     phys_eof - shpp->sh_pool_create_len);
 403                         }
 404                 }
 405         }
 406
 407         /* offset for consumer to use next */
 408         *offp += read_len + leftover;
 409
 410         /* tell the consumer how much you actually read */
 411         *len = read_len + leftover;
 412
 413         if (read_len == 0) {
 414                 mutex_exit(&spa->spa_history_lock);
 415                 dmu_buf_rele(dbp, FTAG);
 416                 return (0);
 417         }
 418
 419         err = dmu_read(mos, spa->spa_history, phys_read_off, read_len, buf,
 420             DMU_READ_PREFETCH);
 421         if (leftover && err == 0) {
 422                 err = dmu_read(mos, spa->spa_history, shpp->sh_pool_create_len,
 423                     leftover, buf + read_len, DMU_READ_PREFETCH);
 424         }
 425         mutex_exit(&spa->spa_history_lock);
 426
 427         dmu_buf_rele(dbp, FTAG);
 428         return (err);
 429 }
 430
 431 static void
 432 log_internal(history_internal_events_t event, spa_t *spa,
 433     dmu_tx_t *tx, const char *fmt, va_list adx)
 434 {
 435         history_arg_t *ha;
 436         va_list adx_copy;
 437
 438         /*
 439          * If this is part of creating a pool, not everything is
 440          * initialized yet, so don't bother logging the internal events.
 441          */
 442         if (tx->tx_txg == TXG_INITIAL)
 443                 return;
 444
 445         ha = kmem_alloc(sizeof (history_arg_t), KM_PUSHPAGE);
 446         va_copy(adx_copy, adx);
 447         ha->ha_history_str = kmem_vasprintf(fmt, adx_copy);
 448         va_end(adx_copy);
 449         ha->ha_log_type = LOG_INTERNAL;
 450         ha->ha_event = event;
 451         ha->ha_zone = NULL;
 452         ha->ha_uid = 0;
 453
 454         if (dmu_tx_is_syncing(tx)) {
 455                 spa_history_log_sync(spa, ha, tx);
 456         } else {
 457                 dsl_sync_task_do_nowait(spa_get_dsl(spa), NULL,
 458                     spa_history_log_sync, spa, ha, 0, tx);
 459         }
 460         /* spa_history_log_sync() will free ha and strings */
 461 }
 462
 463 void
 464 spa_history_log_internal(history_internal_events_t event, spa_t *spa,
 465     dmu_tx_t *tx, const char *fmt, ...)
 466 {
 467         dmu_tx_t *htx = tx;
 468         va_list adx;
 469
 470         /* create a tx if we didn't get one */
 471         if (tx == NULL) {
 472                 htx = dmu_tx_create_dd(spa_get_dsl(spa)->dp_mos_dir);
 473                 if (dmu_tx_assign(htx, TXG_WAIT) != 0) {
 474                         dmu_tx_abort(htx);
 475                         return;
 476                 }
 477         }
 478
 479         va_start(adx, fmt);
 480         log_internal(event, spa, htx, fmt, adx);
 481         va_end(adx);
 482
 483         /* if we didn't get a tx from the caller, commit the one we made */
 484         if (tx == NULL)
 485                 dmu_tx_commit(htx);
 486 }
 487
 488 void
 489 spa_history_log_version(spa_t *spa, history_internal_events_t event)
 490 {
 491 #ifdef _KERNEL
 492         uint64_t current_vers = spa_version(spa);
 493
 494         if (current_vers >= SPA_VERSION_ZPOOL_HISTORY) {
 495                 spa_history_log_internal(event, spa, NULL,
 496                     "pool spa %llu; zfs spa %llu; zpl %d; uts %s %s %s %s",
 497                     (u_longlong_t)current_vers, SPA_VERSION, ZPL_VERSION,
 498                     utsname.nodename, utsname.release, utsname.version,
 499                     utsname.machine);
 500         }
 501         cmn_err(CE_CONT, "!%s version %llu pool %s using %llu",
 502             event == LOG_POOL_IMPORT ? "imported" :
 503             event == LOG_POOL_CREATE ? "created" : "accessed",
 504             (u_longlong_t)current_vers, spa_name(spa), SPA_VERSION);
 505 #endif
 506 }
 507
 508 #if defined(_KERNEL) && defined(HAVE_SPL)
 509 EXPORT_SYMBOL(spa_history_create_obj);
 510 EXPORT_SYMBOL(spa_history_get);
 511 EXPORT_SYMBOL(spa_history_log);
 512 EXPORT_SYMBOL(spa_history_log_internal);
 513 EXPORT_SYMBOL(spa_history_log_version);
 514 #endif