Emit history events for 'zpool create'

History commands and events were being suppressed for the 'zpool create' command since the history object did not yet exist. Create the object earlier so this history doesn't get lost. Split the pool_destroy event in to pool_destroy and pool_export so they may be distinguished. Updated events_001_pos and events_002_pos test cases. They now check for the expected history events and were reworked to be more reliable. NOTE: Custom event runfile added to verify reliability. This will be removed in the final merge. Signed-off-by: Brian Behlendorf <behlendorf1@llnl.gov> Issue openzfs#6486
behlendorf · Oct 20, 2017 · 8077ea8 · 8077ea8
1 parent 6044cf5
commit 8077ea8
Show file tree

Hide file tree

Showing 11 changed files with 182 additions and 72 deletions.
diff --git a/TEST b/TEST
@@ -8,13 +8,13 @@
 #TEST_SPLAT_OPTIONS="-acvx"
 
 ### ztest
-#TEST_ZTEST_SKIP="yes"
+TEST_ZTEST_SKIP="yes"
 #TEST_ZTEST_TIMEOUT=1800
 #TEST_ZTEST_DIR="/var/tmp/"
 #TEST_ZTEST_OPTIONS="-V"
 
 ### zimport
-#TEST_ZIMPORT_SKIP="yes"
+TEST_ZIMPORT_SKIP="yes"
 #TEST_ZIMPORT_DIR="/var/tmp/zimport"
 #TEST_ZIMPORT_VERSIONS="master installed"
 #TEST_ZIMPORT_POOLS="zol-0.6.1 zol-0.6.2 master installed"
@@ -33,10 +33,10 @@
 #TEST_ZFSTESTS_SKIP="yes"
 #TEST_ZFSTESTS_DISKS="vdb vdc vdd"
 #TEST_ZFSTESTS_DISKSIZE="8G"
-#TEST_ZFSTESTS_RUNFILE="linux.run"
+TEST_ZFSTESTS_RUNFILE="events.run"
 
 ### zfsstress
-#TEST_ZFSSTRESS_SKIP="yes"
+TEST_ZFSSTRESS_SKIP="yes"
 #TEST_ZFSSTRESS_URL="https://github.com/nedbass/zfsstress/archive/"
 #TEST_ZFSSTRESS_VER="master.tar.gz"
 #TEST_ZFSSTRESS_RUNTIME=300

diff --git a/include/sys/spa.h b/include/sys/spa.h
@@ -1005,7 +1005,8 @@ extern int spa_history_get(spa_t *spa, uint64_t *offset, uint64_t *len_read,
     char *his_buf);
 extern int spa_history_log(spa_t *spa, const char *his_buf);
 extern int spa_history_log_nvl(spa_t *spa, nvlist_t *nvl);
-extern void spa_history_log_version(spa_t *spa, const char *operation);
+extern void spa_history_log_version(spa_t *spa, const char *operation,
+    dmu_tx_t *tx);
 extern void spa_history_log_internal(spa_t *spa, const char *operation,
     dmu_tx_t *tx, const char *fmt, ...);
 extern void spa_history_log_internal_ds(struct dsl_dataset *ds, const char *op,

diff --git a/include/sys/sysevent/eventdefs.h b/include/sys/sysevent/eventdefs.h
@@ -101,6 +101,7 @@ extern "C" {
 #define	ESC_ZFS_POOL_CREATE		"pool_create"
 #define	ESC_ZFS_POOL_DESTROY		"pool_destroy"
 #define	ESC_ZFS_POOL_IMPORT		"pool_import"
+#define	ESC_ZFS_POOL_EXPORT		"pool_export"
 #define	ESC_ZFS_VDEV_ADD		"vdev_add"
 #define	ESC_ZFS_VDEV_ATTACH		"vdev_attach"
 #define	ESC_ZFS_VDEV_CLEAR		"vdev_clear"

diff --git a/module/zfs/spa.c b/module/zfs/spa.c
@@ -3265,7 +3265,7 @@ spa_load_impl(spa_t *spa, uint64_t pool_guid, nvlist_t *config,
 		 * Log the fact that we booted up (so that we can detect if
 		 * we rebooted in the middle of an operation).
 		 */
-		spa_history_log_version(spa, "open");
+		spa_history_log_version(spa, "open", NULL);
 
 		/*
 		 * Delete any inconsistent datasets.
@@ -4183,6 +4183,15 @@ spa_create(const char *pool, nvlist_t *nvroot, nvlist_t *props,
 
 	tx = dmu_tx_create_assigned(dp, txg);
 
+	/*
+	 * Create the pool's history object.
+	 */
+	if (version >= SPA_VERSION_ZPOOL_HISTORY && !spa->spa_history)
+		spa_history_create_obj(spa, tx);
+
+	spa_event_notify(spa, NULL, NULL, ESC_ZFS_POOL_CREATE);
+	spa_history_log_version(spa, "create", tx);
+
 	/*
 	 * Create the pool config object.
 	 */
@@ -4228,12 +4237,6 @@ spa_create(const char *pool, nvlist_t *nvroot, nvlist_t *props,
 	VERIFY3U(0, ==, bpobj_open(&spa->spa_deferred_bpobj,
 	    spa->spa_meta_objset, obj));
 
-	/*
-	 * Create the pool's history object.
-	 */
-	if (version >= SPA_VERSION_ZPOOL_HISTORY)
-		spa_history_create_obj(spa, tx);
-
 	/*
 	 * Generate some random noise for salted checksums to operate on.
 	 */
@@ -4278,9 +4281,6 @@ spa_create(const char *pool, nvlist_t *nvroot, nvlist_t *props,
 		VERIFY0(spa_keystore_remove_mapping(spa, root_dsobj, FTAG));
 
 	spa_config_sync(spa, B_FALSE, B_TRUE);
-	spa_event_notify(spa, NULL, NULL, ESC_ZFS_POOL_CREATE);
-
-	spa_history_log_version(spa, "create");
 
 	/*
 	 * Don't count references from objsets that are already closed
@@ -4467,7 +4467,7 @@ spa_import(char *pool, nvlist_t *config, nvlist_t *props, uint64_t flags)
 	 */
 	spa_async_request(spa, SPA_ASYNC_AUTOEXPAND);
 
-	spa_history_log_version(spa, "import");
+	spa_history_log_version(spa, "import", NULL);
 
 	spa_event_notify(spa, NULL, NULL, ESC_ZFS_POOL_IMPORT);
 
@@ -4670,7 +4670,10 @@ spa_export_common(char *pool, int new_state, nvlist_t **oldconfig,
 	}
 
 export_spa:
-	spa_event_notify(spa, NULL, NULL, ESC_ZFS_POOL_DESTROY);
+	if (new_state == POOL_STATE_DESTROYED)
+		spa_event_notify(spa, NULL, NULL, ESC_ZFS_POOL_DESTROY);
+	else if (new_state == POOL_STATE_EXPORTED)
+		spa_event_notify(spa, NULL, NULL, ESC_ZFS_POOL_EXPORT);
 
 	if (spa->spa_state != POOL_STATE_UNINITIALIZED) {
 		spa_unload(spa);

diff --git a/module/zfs/spa_history.c b/module/zfs/spa_history.c
@@ -89,17 +89,17 @@ spa_history_create_obj(spa_t *spa, dmu_tx_t *tx)
 	spa_history_phys_t *shpp;
 	objset_t *mos = spa->spa_meta_objset;
 
-	ASSERT(spa->spa_history == 0);
+	ASSERT0(spa->spa_history);
 	spa->spa_history = dmu_object_alloc(mos, DMU_OT_SPA_HISTORY,
 	    SPA_OLD_MAXBLOCKSIZE, DMU_OT_SPA_HISTORY_OFFSETS,
 	    sizeof (spa_history_phys_t), tx);
 
-	VERIFY(zap_add(mos, DMU_POOL_DIRECTORY_OBJECT,
+	VERIFY0(zap_add(mos, DMU_POOL_DIRECTORY_OBJECT,
 	    DMU_POOL_HISTORY, sizeof (uint64_t), 1,
-	    &spa->spa_history, tx) == 0);
+	    &spa->spa_history, tx));
 
-	VERIFY(0 == dmu_bonus_hold(mos, spa->spa_history, FTAG, &dbp));
-	ASSERT(dbp->db_size >= sizeof (spa_history_phys_t));
+	VERIFY0(dmu_bonus_hold(mos, spa->spa_history, FTAG, &dbp));
+	ASSERT3U(dbp->db_size, >=, sizeof (spa_history_phys_t));
 
 	shpp = dbp->db_data;
 	dmu_buf_will_dirty(dbp, tx);
@@ -530,7 +530,7 @@ log_internal(nvlist_t *nvl, const char *operation, spa_t *spa,
 	 * initialized yet, so don't bother logging the internal events.
 	 * Likewise if the pool is not writeable.
 	 */
-	if (tx->tx_txg == TXG_INITIAL || !spa_writeable(spa)) {
+	if (spa_is_initializing(spa) || !spa_writeable(spa)) {
 		fnvlist_free(nvl);
 		return;
 	}
@@ -616,11 +616,11 @@ spa_history_log_internal_dd(dsl_dir_t *dd, const char *operation,
 }
 
 void
-spa_history_log_version(spa_t *spa, const char *operation)
+spa_history_log_version(spa_t *spa, const char *operation, dmu_tx_t *tx)
 {
 	utsname_t *u = utsname();
 
-	spa_history_log_internal(spa, operation, NULL,
+	spa_history_log_internal(spa, operation, tx,
 	    "pool version %llu; software version %llu/%llu; uts %s %s %s %s",
 	    (u_longlong_t)spa_version(spa), SPA_VERSION, ZPL_VERSION,
 	    u->nodename, u->release, u->version, u->machine);

diff --git a/tests/runfiles/events.run b/tests/runfiles/events.run
@@ -0,0 +1,48 @@
+#
+# This file and its contents are supplied under the terms of the
+# Common Development and Distribution License ("CDDL"), version 1.0.
+# You may only use this file in accordance with the terms of version
+# 1.0 of the CDDL.
+#
+# A full copy of the text of the CDDL should have accompanied this
+# source.  A copy of the CDDL is also available via the Internet at
+# http://www.illumos.org/license/CDDL.
+#
+
+[DEFAULT]
+pre = setup
+quiet = False
+pre_user = root
+user = root
+timeout = 600
+post_user = root
+post = cleanup
+outputdir = /var/tmp/test_results
+
+[tests/functional/events]
+tests = ['events_001_pos', 'events_002_pos', 'events_001_pos',
+    'events_002_pos', 'events_001_pos', 'events_002_pos', 'events_001_pos',
+    'events_002_pos', 'events_001_pos', 'events_002_pos', 'events_001_pos',
+    'events_002_pos', 'events_001_pos', 'events_002_pos', 'events_001_pos',
+    'events_002_pos', 'events_001_pos', 'events_002_pos', 'events_001_pos',
+    'events_002_pos', 'events_001_pos', 'events_002_pos', 'events_001_pos',
+    'events_002_pos', 'events_001_pos', 'events_002_pos', 'events_001_pos',
+    'events_002_pos', 'events_001_pos', 'events_002_pos', 'events_001_pos',
+    'events_002_pos', 'events_001_pos', 'events_002_pos', 'events_001_pos',
+    'events_002_pos', 'events_001_pos', 'events_002_pos', 'events_001_pos',
+    'events_002_pos', 'events_001_pos', 'events_002_pos', 'events_001_pos',
+    'events_002_pos', 'events_001_pos', 'events_002_pos', 'events_001_pos',
+    'events_002_pos', 'events_001_pos', 'events_002_pos', 'events_001_pos',
+    'events_002_pos', 'events_001_pos', 'events_002_pos', 'events_001_pos',
+    'events_002_pos', 'events_001_pos', 'events_002_pos', 'events_001_pos',
+    'events_002_pos', 'events_001_pos', 'events_002_pos', 'events_001_pos',
+    'events_002_pos', 'events_001_pos', 'events_002_pos', 'events_001_pos',
+    'events_002_pos', 'events_001_pos', 'events_002_pos', 'events_001_pos',
+    'events_002_pos', 'events_001_pos', 'events_002_pos', 'events_001_pos',
+    'events_002_pos', 'events_001_pos', 'events_002_pos', 'events_001_pos',
+    'events_002_pos', 'events_001_pos', 'events_002_pos', 'events_001_pos',
+    'events_002_pos', 'events_001_pos', 'events_002_pos', 'events_001_pos',
+    'events_002_pos', 'events_001_pos', 'events_002_pos', 'events_001_pos',
+    'events_002_pos', 'events_001_pos', 'events_002_pos', 'events_001_pos',
+    'events_002_pos', 'events_001_pos', 'events_002_pos', 'events_001_pos',
+    'events_002_pos']
diff --git a/tests/zfs-tests/include/default.cfg.in b/tests/zfs-tests/include/default.cfg.in
@@ -179,6 +179,8 @@ if is_linux; then
 	DEV_MPATHDIR="/dev/mapper"
 
 	ZEDLET_DIR="/var/tmp/zed"
+	ZED_LOG="$ZEDLET_DIR/zed.log"
+	ZED_DEBUG_LOG="$ZEDLET_DIR/zed.debug.log"
 	VDEVID_CONF="$ZEDLET_DIR/vdev_id.conf"
 	VDEVID_CONF_ETC="/etc/zfs/vdev_id.conf"
 
@@ -200,4 +202,4 @@ else
 fi
 export unpack_opts pack_opts verbose unpack_preserve pack_preserve \
        ZVOL_DEVDIR ZVOL_RDEVDIR NEWFS_DEFAULT_FS DEV_RDSKDIR DEV_MPATHDIR \
-       ZEDLET_DIR VDEVID_CONF VDEVID_CONF_ETC
+       ZEDLET_DIR ZED_LOG ZED_DEBUG_LOG VDEVID_CONF VDEVID_CONF_ETC
diff --git a/tests/zfs-tests/include/libtest.shlib b/tests/zfs-tests/include/libtest.shlib
@@ -3361,11 +3361,13 @@ function zed_setup
 
 	# Customize the zed.rc file to enable the full debug log.
 	log_must sed -i '/\#ZED_DEBUG_LOG=.*/d' $ZEDLET_DIR/zed.rc
-	echo "ZED_DEBUG_LOG=$ZEDLET_DIR/zed.debug.log" >>$ZEDLET_DIR/zed.rc
+	echo "ZED_DEBUG_LOG=$ZED_DEBUG_LOG" >>$ZEDLET_DIR/zed.rc
 
+	saved_umask=$(umask)
+	log_must umask 0022
 	log_must cp ${ZEDLET_LIBEXEC_DIR}/all-syslog.sh $ZEDLET_DIR
 	log_must cp ${ZEDLET_LIBEXEC_DIR}/all-debug.sh $ZEDLET_DIR
-	log_must touch $ZEDLET_DIR/zed.debug.log
+	log_must umask $saved_umask
 }
 
 #
@@ -3381,10 +3383,9 @@ function zed_cleanup
 	log_must rm -f ${ZEDLET_DIR}/zed-functions.sh
 	log_must rm -f ${ZEDLET_DIR}/all-syslog.sh
 	log_must rm -f ${ZEDLET_DIR}/all-debug.sh
-	log_must rm -f ${ZEDLET_DIR}/zed.pid
-	log_must rm -f ${ZEDLET_DIR}/zedlog
-	log_must rm -f ${ZEDLET_DIR}/zed.debug.log
 	log_must rm -f ${ZEDLET_DIR}/state
+	log_must rm -f $ZED_LOG
+	log_must rm -f $ZED_DEBUG_LOG
 	log_must rm -f $VDEVID_CONF_ETC
 	log_must rm -f $VDEVID_CONF
 	rmdir $ZEDLET_DIR
@@ -3412,9 +3413,10 @@ function zed_start
 
 	log_note "Starting ZED"
 	# run ZED in the background and redirect foreground logging
-	# output to zedlog
+	# output to $ZED_LOG.
+	log_must truncate -s 0 $ZED_DEBUG_LOG
 	log_must eval "zed -vF -d $ZEDLET_DIR -p $ZEDLET_DIR/zed.pid" \
-	    "-s $ZEDLET_DIR/state 2>${ZEDLET_DIR}/zedlog &"
+	    "-s $ZEDLET_DIR/state 2>$ZED_LOG &"
 
 	return 0
 }
@@ -3431,7 +3433,9 @@ function zed_stop
 	log_note "Stopping ZED"
 	if [[ -f ${ZEDLET_DIR}/zed.pid ]]; then
 		zedpid=$(cat ${ZEDLET_DIR}/zed.pid)
-		log_must kill $zedpid
+		kill $zedpid
+		wait $zedpid
+		rm -f ${ZEDLET_DIR}/zed.pid
 	fi
 
 	return 0

diff --git a/tests/zfs-tests/tests/functional/events/events_001_pos.ksh b/tests/zfs-tests/tests/functional/events/events_001_pos.ksh
@@ -55,14 +55,22 @@ log_assert "Verify zpool sub-commands generate expected events"
 log_onexit cleanup
 
 log_must truncate -s $MINVDEVSIZE $VDEV1 $VDEV2 $VDEV3 $VDEV4
+
+log_must zpool events -c
 log_must zed_start
 
 # Create a mirrored pool with two devices.
 run_and_verify -p "$MPOOL" \
-    -e "sysevent.fs.zfs.config_sync" \
     -e "sysevent.fs.zfs.pool_create" \
+    -e "sysevent.fs.zfs.history_event" \
+    -e "sysevent.fs.zfs.config_sync" \
     "zpool create $MPOOL mirror $VDEV1 $VDEV2"
 
+# Set a pool property.
+run_and_verify -p "$MPOOL" \
+    -e "sysevent.fs.zfs.history_event" \
+    "zpool set comment=string $MPOOL"
+
 # Add a cache device then remove it.
 run_and_verify -p "$MPOOL" \
     -e "sysevent.fs.zfs.config_sync" \
@@ -86,42 +94,53 @@ run_and_verify -p "$MPOOL"\
     -e "resource.fs.zfs.statechange" \
     -e "sysevent.fs.zfs.config_sync" \
     "zpool offline $MPOOL $VDEV1"
-run_and_verify -p "$MPOOL" \
+run_and_verify -p "$MPOOL" -d 10 \
     -e "resource.fs.zfs.statechange" \
     -e "sysevent.fs.zfs.vdev_online" \
+    -e "sysevent.fs.zfs.resilver_start" \
+    -e "sysevent.fs.zfs.resilver_finish" \
+    -e "sysevent.fs.zfs.history_event" \
     -e "sysevent.fs.zfs.config_sync" \
     "zpool online $MPOOL $VDEV1"
 
 # Attach then detach a device from the mirror.
-run_and_verify -p "$MPOOL" \
-     -e "sysevent.fs.zfs.vdev_attach" \
+run_and_verify -p "$MPOOL" -d 10 \
+    -e "sysevent.fs.zfs.vdev_attach" \
+    -e "sysevent.fs.zfs.resilver_start" \
+    -e "sysevent.fs.zfs.resilver_finish" \
+    -e "sysevent.fs.zfs.history_event" \
+    -e "sysevent.fs.zfs.config_sync" \
     "zpool attach $MPOOL $VDEV1 $VDEV4"
 run_and_verify -p "$MPOOL" \
     -e "sysevent.fs.zfs.vdev_remove" \
     -e "sysevent.fs.zfs.config_sync" \
     "zpool detach $MPOOL $VDEV4"
 
 # Replace a device
-run_and_verify -p "$MPOOL" \
+run_and_verify -p "$MPOOL" -d 10 \
     -e "sysevent.fs.zfs.vdev_attach" \
     -e "sysevent.fs.zfs.resilver_start" \
     -e "sysevent.fs.zfs.resilver_finish" \
+    -e "sysevent.fs.zfs.vdev_remove" \
+    -e "sysevent.fs.zfs.history_event" \
     -e "sysevent.fs.zfs.config_sync" \
     "zpool replace -f $MPOOL $VDEV1 $VDEV4"
 
 # Scrub a pool.
-run_and_verify -p "$MPOOL" \
+run_and_verify -p "$MPOOL" -d 10 \
     -e "sysevent.fs.zfs.scrub_start" \
     -e "sysevent.fs.zfs.scrub_finish" \
+    -e "sysevent.fs.zfs.history_event" \
     "zpool scrub $MPOOL"
 
-# Export then import a pool (may change to a pool_export event)
+# Export then import a pool
 run_and_verify -p "$MPOOL" \
-    -e "sysevent.fs.zfs.pool_destroy" \
+    -e "sysevent.fs.zfs.pool_export" \
     -e "sysevent.fs.zfs.config_sync" \
     "zpool export $MPOOL"
 run_and_verify -p "$MPOOL" \
     -e "sysevent.fs.zfs.pool_import" \
+    -e "sysevent.fs.zfs.history_event" \
     -e "sysevent.fs.zfs.config_sync" \
     "zpool import -d $TEST_BASE_DIR $MPOOL"