TEST ONLY Force blk-mq to be unsettable for sanity

Signed-off-by: Tony Hutter <hutter2@llnl.gov>
Requires-builders: fedora38

include/sys/zil.h

@@ -596,6 +596,13 @@ extern void zil_kstat_values_update(zil_kstat_values_t *zs,
 
 extern int zil_replay_disable;
 
+void zil_log_clear(void);
+
+void zil_log(zilog_t *zilog, const char* fmt, ...);
+void zil_log_print(zilog_t *zilog);
+void zil_log_blkptr(const blkptr_t *bp);
+
+
 #ifdef	__cplusplus
 }
 #endif

include/sys/zil_impl.h

@@ -166,6 +166,7 @@ typedef struct zil_vdev_node {
 
 #define	ZIL_PREV_BLKS 16
 
+#define ZIL_LOG_LEN 150
 /*
  * Stable storage intent log management structure.  One per dataset.
  */

module/os/linux/zfs/zvol_os.c

@@ -1602,8 +1602,8 @@ MODULE_PARM_DESC(zvol_volmode, "Default volmode property value");
 module_param(zvol_blk_mq_queue_depth, uint, 0644);
 MODULE_PARM_DESC(zvol_blk_mq_queue_depth, "Default blk-mq queue depth");
 
-module_param(zvol_use_blk_mq, uint, 0644);
-MODULE_PARM_DESC(zvol_use_blk_mq, "Use the blk-mq API for zvols");
+// module_param(zvol_use_blk_mq, uint, 0644);
+// MODULE_PARM_DESC(zvol_use_blk_mq, "Use the blk-mq API for zvols");
 
 module_param(zvol_blk_mq_blocks_per_thread, uint, 0644);
 MODULE_PARM_DESC(zvol_blk_mq_blocks_per_thread,

module/zfs/dmu_objset.c

@@ -66,6 +66,7 @@
 #include "zfs_namecheck.h"
 #include <sys/vdev_impl.h>
 #include <sys/arc.h>
+#include <sys/zil_impl.h>
 
 /*
  * Needed to close a window in dnode_move() that allows the objset to be freed
@@ -462,6 +463,8 @@ dmu_objset_open_impl(spa_t *spa, dsl_dataset_t *ds, blkptr_t *bp,
 	 * We need the pool config lock to get properties.
 	 */
 	ASSERT(ds == NULL || dsl_pool_config_held(ds->ds_dir->dd_pool));
+//	zil_log_clear();
+	zil_log(NULL, "%s: begin", __func__);
 
 	/*
 	 * The $ORIGIN dataset (if it exists) doesn't have an associated
@@ -478,6 +481,7 @@ dmu_objset_open_impl(spa_t *spa, dsl_dataset_t *ds, blkptr_t *bp,
 	os->os_dsl_dataset = ds;
 	os->os_spa = spa;
 	os->os_rootbp = bp;
+
 	if (!BP_IS_HOLE(os->os_rootbp)) {
 		arc_flags_t aflags = ARC_FLAG_WAIT;
 		zbookmark_phys_t zb;
@@ -495,6 +499,9 @@ dmu_objset_open_impl(spa_t *spa, dsl_dataset_t *ds, blkptr_t *bp,
 			zio_flags |= ZIO_FLAG_RAW;
 		}
 
+		zil_log(NULL, "%s: reading os_rootbp", __func__);
+		zil_log_blkptr(os->os_rootbp);
+
 		dprintf_bp(os->os_rootbp, "reading %s", "");
 		err = arc_read(NULL, spa, os->os_rootbp,
 		    arc_getbuf_func, &os->os_phys_buf,
@@ -528,14 +535,19 @@ dmu_objset_open_impl(spa_t *spa, dsl_dataset_t *ds, blkptr_t *bp,
 
 		os->os_phys = os->os_phys_buf->b_data;
 		os->os_flags = os->os_phys->os_flags;
+		zil_log(NULL, "%s: its not a hole txg %llu", __func__, os->os_phys->os_zil_header.zh_claim_txg);
+
 	} else {
+		zil_log(NULL, "%s: its a hole, zero", __func__);
+
 		int size = spa_version(spa) >= SPA_VERSION_USERSPACE ?
 		    sizeof (objset_phys_t) : OBJSET_PHYS_SIZE_V1;
 		os->os_phys_buf = arc_alloc_buf(spa, &os->os_phys_buf,
 		    ARC_BUFC_METADATA, size);
 		os->os_phys = os->os_phys_buf->b_data;
 		memset(os->os_phys, 0, size);
 	}
+
 	/*
 	 * These properties will be filled in by the logic in zfs_get_zplprop()
 	 * when they are queried for the first time.
@@ -637,10 +649,21 @@ dmu_objset_open_impl(spa_t *spa, dsl_dataset_t *ds, blkptr_t *bp,
 		os->os_dnodesize = DNODE_MIN_SIZE;
 	}
 
-	if (ds == NULL || !ds->ds_is_snapshot)
+	if (ds == NULL || !ds->ds_is_snapshot) {
+
+		zil_log(NULL, "%s: using os_phys txg %llu", __func__, os->os_phys->os_zil_header.zh_claim_txg);
 		os->os_zil_header = os->os_phys->os_zil_header;
+	}
+
 	os->os_zil = zil_alloc(os, &os->os_zil_header);
 
+
+#ifdef _KERNEL
+       zil_log(os->os_zil, "%s: after zil alloc %p txg %llu, txg os_zil_header %llu, os->os_phys->os_zil_header %p", __func__, os->os_zil->zl_header, os->os_zil->zl_header->zh_claim_txg,
+		os->os_phys->os_zil_header.zh_claim_txg, os->os_phys->os_zil_header);
+#endif
+
+
 	for (i = 0; i < TXG_SIZE; i++) {
 		multilist_create(&os->os_dirty_dnodes[i], sizeof (dnode_t),
 		    offsetof(dnode_t, dn_dirty_link[i]),
@@ -1657,6 +1680,8 @@ dmu_objset_sync(objset_t *os, zio_t *pio, dmu_tx_t *tx)
 	multilist_t *ml;
 	blkptr_t *blkptr_copy = kmem_alloc(sizeof (*os->os_rootbp), KM_SLEEP);
 	*blkptr_copy = *os->os_rootbp;
+	zil_log_clear();
+	zil_log(NULL, "%s: begin txg %d", __func__, os->os_phys->os_zil_header.zh_claim_txg);
 
 	dprintf_ds(os->os_dsl_dataset, "txg=%llu\n", (u_longlong_t)tx->tx_txg);
 
@@ -1773,6 +1798,8 @@ dmu_objset_sync(objset_t *os, zio_t *pio, dmu_tx_t *tx)
 	zil_sync(os->os_zil, tx);
 	os->os_phys->os_zil_header = os->os_zil_header;
 	zio_nowait(zio);
+	zil_log(NULL, "%s: finish txg %d", __func__, os->os_phys->os_zil_header.zh_claim_txg);
+
 }
 
 boolean_t

module/zfs/dmu_traverse.c

@@ -38,6 +38,7 @@
 #include <sys/sa_impl.h>
 #include <sys/callb.h>
 #include <sys/zfeature.h>
+#include <sys/zil_impl.h>
 
 static int32_t zfs_pd_bytes_max = 50 * 1024 * 1024;	/* 50MB */
 static int32_t send_holes_without_birth_time = 1;
@@ -134,6 +135,9 @@ traverse_zil(traverse_data_t *td, zil_header_t *zh)
 		return;
 
 	zilog_t *zilog = zil_alloc(spa_get_dsl(td->td_spa)->dp_meta_objset, zh);
+#ifdef _KERNEL
+	zil_log(NULL, "%s: begin %p txg %llu", __func__, zilog->zl_header,  zilog->zl_header->zh_claim_txg);
+#endif
 	(void) zil_parse(zilog, traverse_zil_block, traverse_zil_record, td,
 	    claim_txg, !(td->td_flags & TRAVERSE_NO_DECRYPT));
 	zil_free(zilog);

module/zfs/dsl_scan.c

@@ -1512,6 +1512,9 @@ dsl_scan_zil(dsl_pool_t *dp, zil_header_t *zh)
 		return;
 
 	zilog = zil_alloc(dp->dp_meta_objset, zh);
+#ifdef _KERNEL
+       zil_log(NULL, "%s: begin %p txg %llu", __func__, zilog->zl_header,  zilog->zl_header->zh_claim_txg);
+#endif
 
 	(void) zil_parse(zilog, dsl_scan_zil_block, dsl_scan_zil_record, &zsa,
 	    claim_txg, B_FALSE);

module/zfs/zil.c

@@ -46,6 +46,12 @@
 #include <sys/brt.h>
 #include <sys/wmsum.h>
 
+#ifdef _KERNEL
+#include <linux/module.h>  /* Needed by all modules */
+#include <linux/timekeeping.h>
+#endif
+
+
 /*
  * The ZFS Intent Log (ZIL) saves "transaction records" (itxs) of system
  * calls that change the file system. Each itx has enough information to
@@ -146,6 +152,64 @@ static uint64_t zil_slog_bulk = 768 * 1024;
 static kmem_cache_t *zil_lwb_cache;
 static kmem_cache_t *zil_zcw_cache;
 
+static uint64_t pos = 0;
+#define CHARS_PER_LINE 512
+static char log[ZIL_LOG_LEN][CHARS_PER_LINE] = {0}; 
+
+void zil_log_clear(void)
+{
+	pos = 0;
+	memset(log, 0, ZIL_LOG_LEN * CHARS_PER_LINE); 
+}
+
+void zil_log(zilog_t *zilog __attribute__((unused)), const char* fmt, ...)
+{
+    va_list args;
+    va_start(args, fmt);
+    pos++;
+
+    if (pos >= ZIL_LOG_LEN - 1) {
+	zil_log_clear();    	
+    	goto end;
+	}	
+#ifdef _KERNEL
+    sprintf(log[pos], "%llu ", ktime_get_coarse_ns());
+#endif
+
+    vsprintf(&log[pos][strlen(log[pos])], fmt, args);
+end:
+    va_end(args);
+}
+
+void zil_log_blkptr(const blkptr_t *bp __attribute__((unused)))
+{
+
+#ifdef _KERNEL
+    pos++;
+
+    if (pos >= ZIL_LOG_LEN - 1) {
+	    zil_log_clear();    	
+	    return;
+    }	
+    sprintf(log[pos], "%llu ", ktime_get_coarse_ns());
+    snprintf_blkptr(&log[pos][strlen(log[pos])], sizeof(log[pos]), bp);
+
+#endif
+
+}
+
+
+void zil_log_print(zilog_t *zilog __attribute__((unused)))
+{
+#ifdef _KERNEL
+	uint64_t i;
+	for (i = 0; i < pos; i++) {
+		if (log[i][0] != 0)
+			printk("%llu: %s\n", i, log[i]);
+	}
+#endif
+}
+
 static int
 zil_bp_compare(const void *x1, const void *x2)
 {
@@ -894,15 +958,23 @@ zil_create(zilog_t *zilog)
 	boolean_t fastwrite = FALSE;
 	boolean_t slog = FALSE;
 	dsl_dataset_t *ds = dmu_objset_ds(zilog->zl_os);
+	static int print_once = 0;
 
-
+	zil_log(zilog, "%s: begin %p, txg %lu", __func__, zilog->zl_header, zilog->zl_header->zh_claim_txg);
 	/*
 	 * Wait for any previous destroy to complete.
 	 */
 	txg_wait_synced(zilog->zl_dmu_pool, zilog->zl_destroy_txg);
 
+	print_once++;
+	if (print_once % 1000 == 0 || zh->zh_claim_txg != 0) {
+		zil_log_print(zilog);
+	}
+
 	ASSERT3U(zh->zh_claim_txg, ==, 0);
+
 	ASSERT(zh->zh_replay_seq == 0);
+
 
 	blk = zh->zh_log;
 
@@ -1131,6 +1203,7 @@ zil_claim(dsl_pool_t *dp, dsl_dataset_t *ds, void *txarg)
 	if (zh->zh_claim_txg == 0 && !BP_IS_HOLE(&zh->zh_log)) {
 		(void) zil_parse(zilog, zil_claim_log_block,
 		    zil_claim_log_record, tx, first_txg, B_FALSE);
+		zil_log(zilog, "%s: setting %p to %d\n", __func__, zh, first_txg);
 		zh->zh_claim_txg = first_txg;
 		zh->zh_claim_blk_seq = zilog->zl_parse_blk_seq;
 		zh->zh_claim_lr_seq = zilog->zl_parse_lr_seq;
@@ -2569,6 +2642,8 @@ zil_process_commit_list(zilog_t *zilog)
 
 	ASSERT(MUTEX_HELD(&zilog->zl_issuer_lock));
 
+	zil_log(zilog, "%s: begin %p, txg %lu", __func__, zilog->zl_header, zilog->zl_header->zh_claim_txg);
+
 	/*
 	 * Return if there's nothing to commit before we dirty the fs by
 	 * calling zil_create().
@@ -2798,6 +2873,7 @@ zil_commit_writer(zilog_t *zilog, zil_commit_waiter_t *zcw)
 {
 	ASSERT(!MUTEX_HELD(&zilog->zl_lock));
 	ASSERT(spa_writeable(zilog->zl_spa));
+	zil_log(zilog, "%s: begin %p, tag %lu", __func__, zilog->zl_header, zilog->zl_header->zh_claim_txg);
 
 	mutex_enter(&zilog->zl_issuer_lock);
 
@@ -3367,6 +3443,7 @@ zil_sync(zilog_t *zilog, dmu_tx_t *tx)
 	spa_t *spa = zilog->zl_spa;
 	uint64_t *replayed_seq = &zilog->zl_replayed_seq[txg & TXG_MASK];
 	lwb_t *lwb;
+	zil_log(NULL, "%s: begin txg %d", __func__, zilog->zl_header->zh_claim_txg);
 
 	/*
 	 * We don't zero out zl_destroy_txg, so make sure we don't try
@@ -3392,7 +3469,7 @@ zil_sync(zilog_t *zilog, dmu_tx_t *tx)
 		dsl_dataset_t *ds = dmu_objset_ds(zilog->zl_os);
 
 		ASSERT(list_is_empty(&zilog->zl_lwb_list));
-
+		zil_log(zilog, "%s: %p memsetting zh", __func__, zh);
 		memset(zh, 0, sizeof (zil_header_t));
 		memset(zilog->zl_replayed_seq, 0,
 		    sizeof (zilog->zl_replayed_seq));
@@ -3533,8 +3610,15 @@ zil_alloc(objset_t *os, zil_header_t *zh_phys)
 {
 	zilog_t *zilog;
 
+	char name[ZFS_MAX_DATASET_NAME_LEN];
+
 	zilog = kmem_zalloc(sizeof (zilog_t), KM_SLEEP);
 
+	// char name[ZFS_MAX_DATASET_NAME_LEN];
+	/// dmu_objset_name
+
+	dmu_objset_name(os, name);
+
 	zilog->zl_header = zh_phys;
 	zilog->zl_os = os;
 	zilog->zl_spa = dmu_objset_spa(os);
@@ -3547,6 +3631,8 @@ zil_alloc(objset_t *os, zil_header_t *zh_phys)
 	zilog->zl_last_lwb_latency = 0;
 	zilog->zl_max_block_size = zil_maxblocksize;
 
+	zil_log(zilog, "%s: %s allocated %p, txg %lu", __func__, name, zh_phys, zilog->zl_header->zh_claim_txg);
+
 	mutex_init(&zilog->zl_lock, NULL, MUTEX_DEFAULT, NULL);
 	mutex_init(&zilog->zl_issuer_lock, NULL, MUTEX_DEFAULT, NULL);
 	mutex_init(&zilog->zl_lwb_io_lock, NULL, MUTEX_DEFAULT, NULL);
@@ -3622,6 +3708,8 @@ zil_open(objset_t *os, zil_get_data_t *get_data, zil_sums_t *zil_sums)
 	zilog->zl_get_data = get_data;
 	zilog->zl_sums = zil_sums;
 
+	zil_log(zilog, "%s: done %p, txg %lu", __func__, zilog->zl_header, zilog->zl_header->zh_claim_txg);
+
 	return (zilog);
 }
 
@@ -3634,6 +3722,8 @@ zil_close(zilog_t *zilog)
 	lwb_t *lwb;
 	uint64_t txg;
 
+	zil_log(zilog, "%s: begin %p, txg %lu", __func__, zilog->zl_header, zilog->zl_header->zh_claim_txg);
+
 	if (!dmu_objset_is_snapshot(zilog->zl_os)) {
 		zil_commit(zilog, 0);
 	} else {

tests/runfiles/common.run

@@ -947,8 +947,7 @@ tests = ['zvol_cli_001_pos', 'zvol_cli_002_pos', 'zvol_cli_003_neg']
 tags = ['functional', 'zvol', 'zvol_cli']
 
 [tests/functional/zvol/zvol_misc]
-tests = ['zvol_misc_002_pos', 'zvol_misc_hierarchy', 'zvol_misc_rename_inuse',
-    'zvol_misc_snapdev', 'zvol_misc_trim', 'zvol_misc_volmode', 'zvol_misc_zil']
+tests = ['zvol_misc_trim', 'zvol_misc_trim', 'zvol_misc_trim', 'zvol_misc_trim', 'zvol_misc_trim', 'zvol_misc_trim']
 tags = ['functional', 'zvol', 'zvol_misc']
 
 [tests/functional/zvol/zvol_stress]

tests/runfiles/linux.run

@@ -199,10 +199,6 @@ tests = ['groupspace_001_pos', 'groupspace_002_pos', 'groupspace_003_pos',
     'userquota_013_pos', 'userspace_003_pos']
 tags = ['functional', 'userquota']
 
-[tests/functional/zvol/zvol_misc:Linux]
-tests = ['zvol_misc_fua']
-tags = ['functional', 'zvol', 'zvol_misc']
-
 [tests/functional/idmap_mount:Linux]
 tests = ['idmap_mount_001', 'idmap_mount_002', 'idmap_mount_003',
     'idmap_mount_004', 'idmap_mount_005']

tests/zfs-tests/tests/functional/zvol/zvol_misc/zvol_misc_trim.ksh

@@ -130,8 +130,11 @@ log_must $trimcmd $zvolpath
 # do_test
 
 set_blk_mq 0
+echo "exporting pool" > /dev/kmsg
 log_must_busy zpool export $TESTPOOL
+echo "importing pool" > /dev/kmsg
 log_must zpool import $TESTPOOL
+echo "doing test" > /dev/kmsg
 do_test
 
 log_pass "ZFS volumes can be trimmed"