debug

Signed-off-by: Chris Kirby <ckirby@versity.com>

ReleaseNotes.md

@@ -1,6 +1,41 @@
 Versity ScoutFS Release Notes
 =============================
 
+---
+v1.26
+\
+*Nov 17, 2025*
+
+Add the ino\_alloc\_per\_lock mount option.  This changes the number of
+inode numbers allocated under each cluster lock and can alleviate lock
+contention for some patterns of larger file creation.
+
+Add the tcp\_keepalive\_timeout\_ms mount option.  This can enable the
+system to survive longer periods of networking outages.
+
+Fix a rare double free of internal btree metadata blocks when merging
+log trees.  The duplicated freed metadata block numbers would cause
+persistent errors in the server, preventing the server from starting and
+hanging the system.
+
+Fix the data\_wait interface to not require the correct data\_version of
+the inode when raising an error.  This lets callers raise errors when
+they're unable to recall the details of the inode to discover its
+data\_version.
+
+Change scoutfs to more aggressively reclaim cached memory when under
+memory pressure.  This makes scoutfs behave more like other kernel
+components and it integrates better with the reclaim policy heuristics
+in the VM core of the kernel.
+
+Change scoutfs to more efficiently transmit and receive socket messages.
+Under heavy load this can process messages sufficiently more quickly to
+avoid hung task messages for tasks that were waiting for cluster lock
+messages to be processed.
+
+Fix faulty server block commit budget calculations that were generating
+spurious "holders exceeded alloc budget" console messages.
+
 ---
 v1.25
 \

kmod/src/counters.h

@@ -145,7 +145,9 @@
 	EXPAND_COUNTER(lock_shrink_work)			\
 	EXPAND_COUNTER(lock_unlock)				\
 	EXPAND_COUNTER(lock_wait)				\
+	EXPAND_COUNTER(log_merge_complete)			\
 	EXPAND_COUNTER(log_merge_no_finalized)			\
+	EXPAND_COUNTER(log_merge_start)				\
 	EXPAND_COUNTER(log_merge_wait_timeout)			\
 	EXPAND_COUNTER(net_dropped_response)			\
 	EXPAND_COUNTER(net_send_bytes)				\
@@ -160,6 +162,7 @@
 	EXPAND_COUNTER(orphan_scan)				\
 	EXPAND_COUNTER(orphan_scan_attempts)			\
 	EXPAND_COUNTER(orphan_scan_cached)			\
+	EXPAND_COUNTER(orphan_scan_empty)			\
 	EXPAND_COUNTER(orphan_scan_error)			\
 	EXPAND_COUNTER(orphan_scan_item)			\
 	EXPAND_COUNTER(orphan_scan_omap_set)			\

kmod/src/inode.c

@@ -1482,12 +1482,6 @@ static int remove_index_items(struct super_block *sb, u64 ino,
  * Return an allocated and unused inode number.  Returns -ENOSPC if
  * we're out of inode.
  *
- * Each parent directory has its own pool of free inode numbers.  Items
- * are sorted by their inode numbers as they're stored in segments.
- * This will tend to group together files that are created in a
- * directory at the same time in segments.  Concurrent creation across
- * different directories will be stored in their own regions.
- *
  * Inode numbers are never reclaimed.  If the inode is evicted or we're
  * unmounted the pending inode numbers will be lost.  Asking for a
  * relatively small number from the server each time will tend to
@@ -1497,12 +1491,18 @@ static int remove_index_items(struct super_block *sb, u64 ino,
 int scoutfs_alloc_ino(struct super_block *sb, bool is_dir, u64 *ino_ret)
 {
 	DECLARE_INODE_SB_INFO(sb, inf);
+	struct scoutfs_mount_options opts;
 	struct inode_allocator *ia;
 	u64 ino;
 	u64 nr;
 	int ret;
 
-	ia = is_dir ? &inf->dir_ino_alloc : &inf->ino_alloc;
+	scoutfs_options_read(sb, &opts);
+
+	if (is_dir && opts.ino_alloc_per_lock == SCOUTFS_LOCK_INODE_GROUP_NR)
+		ia = &inf->dir_ino_alloc;
+	else
+		ia = &inf->ino_alloc;
 
 	spin_lock(&ia->lock);
 
@@ -1523,6 +1523,17 @@ int scoutfs_alloc_ino(struct super_block *sb, bool is_dir, u64 *ino_ret)
 	*ino_ret = ia->ino++;
 	ia->nr--;
 
+	if (opts.ino_alloc_per_lock != SCOUTFS_LOCK_INODE_GROUP_NR) {
+		nr = ia->ino & SCOUTFS_LOCK_INODE_GROUP_MASK;
+		if (nr >= opts.ino_alloc_per_lock) {
+			nr = SCOUTFS_LOCK_INODE_GROUP_NR - nr;
+			if (nr > ia->nr)
+				nr = ia->nr;
+			ia->ino += nr;
+			ia->nr -= nr;
+		}
+	}
+
 	spin_unlock(&ia->lock);
 	ret = 0;
 out:
@@ -1626,10 +1637,14 @@ int scoutfs_inode_orphan_delete(struct super_block *sb, u64 ino, struct scoutfs_
 				struct scoutfs_lock *primary)
 {
 	struct scoutfs_key key;
+	int ret;
 
 	init_orphan_key(&key, ino);
 
-	return scoutfs_item_delete_force(sb, &key, lock, primary);
+	ret = scoutfs_item_delete_force(sb, &key, lock, primary);
+	trace_scoutfs_inode_orphan_delete(sb, ino, ret);
+
+	return ret;
 }
 
 /*
@@ -1711,6 +1726,8 @@ out:
 		scoutfs_release_trans(sb);
 	scoutfs_inode_index_unlock(sb, &ind_locks);
 
+	trace_scoutfs_delete_inode_end(sb, ino, mode, size, ret);
+
 	return ret;
 }
 
@@ -1806,6 +1823,9 @@ out:
  * they've checked that the inode could really be deleted.  We serialize
  * on a bit in the lock data so that we only have one deletion attempt
  * per inode under this mount's cluster lock.
+ *
+ * Returns -EAGAIN if we either did some cleanup work or are unable to finish
+ * cleaning up this inode right now.
  */
 static int try_delete_inode_items(struct super_block *sb, u64 ino)
 {
@@ -1819,6 +1839,8 @@ static int try_delete_inode_items(struct super_block *sb, u64 ino)
 	int bit_nr;
 	int ret;
 
+	trace_scoutfs_try_delete(sb, ino);
+
 	ret = scoutfs_lock_ino(sb, SCOUTFS_LOCK_WRITE, 0, ino, &lock);
 	if (ret < 0)
 		goto out;
@@ -1831,27 +1853,32 @@ static int try_delete_inode_items(struct super_block *sb, u64 ino)
 
 	/* only one local attempt per inode at a time */
 	if (test_and_set_bit(bit_nr, ldata->trying)) {
-		ret = 0;
+		trace_scoutfs_try_delete_local_busy(sb, ino);
+		ret = -EAGAIN;
 		goto out;
 	}
 	clear_trying = true;
 
 	/* can't delete if it's cached in local or remote mounts */
 	if (scoutfs_omap_test(sb, ino) || test_bit_le(bit_nr, ldata->map.bits)) {
-		ret = 0;
+		trace_scoutfs_try_delete_cached(sb, ino);
+		ret = -EAGAIN;
 		goto out;
 	}
 
 	scoutfs_inode_init_key(&key, ino);
 	ret = lookup_inode_item(sb, &key, &sinode, lock);
 	if (ret < 0) {
-		if (ret == -ENOENT)
+		if (ret == -ENOENT) {
+			trace_scoutfs_try_delete_no_item(sb, ino);
 			ret = 0;
+		}
 		goto out;
 	}
 
 	if (le32_to_cpu(sinode.nlink) > 0) {
-		ret = 0;
+		trace_scoutfs_try_delete_has_links(sb, ino, le32_to_cpu(sinode.nlink));
+		ret = -EAGAIN;
 		goto out;
 	}
 
@@ -1860,8 +1887,10 @@ static int try_delete_inode_items(struct super_block *sb, u64 ino)
 		goto out;
 
 	ret = delete_inode_items(sb, ino, &sinode, lock, orph_lock);
-	if (ret == 0)
+	if (ret == 0) {
+		ret = -EAGAIN;
 		scoutfs_inc_counter(sb, inode_deleted);
+	}
 
 out:
 	if (clear_trying)
@@ -2063,6 +2092,10 @@ void scoutfs_inode_schedule_orphan_dwork(struct super_block *sb)
  * a locally cached inode.  Then we ask the server for the open map
  * containing the inode.  Only if we don't see any cached users do we do
  * the expensive work of acquiring locks to try and delete the items.
+ *
+ * We need to track whether there is any orphan cleanup work remaining so
+ * that tests such as inode-deletion can watch the orphan_scan_empty counter
+ * to determine when inode cleanup from open-unlink scenarios is complete.
  */
 static void inode_orphan_scan_worker(struct work_struct *work)
 {
@@ -2074,11 +2107,14 @@ static void inode_orphan_scan_worker(struct work_struct *work)
 	SCOUTFS_BTREE_ITEM_REF(iref);
 	struct scoutfs_key last;
 	struct scoutfs_key key;
+	bool work_todo = false;
 	u64 group_nr;
 	int bit_nr;
 	u64 ino;
 	int ret;
 
+	trace_scoutfs_orphan_scan_start(sb);
+
 	scoutfs_inc_counter(sb, orphan_scan);
 
 	init_orphan_key(&last, U64_MAX);
@@ -2098,8 +2134,10 @@ static void inode_orphan_scan_worker(struct work_struct *work)
 		init_orphan_key(&key, ino);
 		ret = scoutfs_btree_next(sb, &roots.fs_root, &key, &iref);
 		if (ret < 0) {
-			if (ret == -ENOENT)
+			if (ret == -ENOENT) {
+				trace_scoutfs_orphan_scan_work(sb, 0);
 				break;
+			}
 			goto out;
 		}
 
@@ -2114,6 +2152,7 @@ static void inode_orphan_scan_worker(struct work_struct *work)
 
 		/* locally cached inodes will try to delete as they evict */
 		if (scoutfs_omap_test(sb, ino)) {
+			work_todo = true;
 			scoutfs_inc_counter(sb, orphan_scan_cached);
 			continue;
 		}
@@ -2129,13 +2168,22 @@ static void inode_orphan_scan_worker(struct work_struct *work)
 
 		/* remote cached inodes will also try to delete */
 		if (test_bit_le(bit_nr, omap.bits)) {
+			work_todo = true;
 			scoutfs_inc_counter(sb, orphan_scan_omap_set);
 			continue;
 		}
 
 		/* seemingly orphaned and unused, get locks and check for sure */
 		scoutfs_inc_counter(sb, orphan_scan_attempts);
+		trace_scoutfs_orphan_scan_work(sb, ino);
+
 		ret = try_delete_inode_items(sb, ino);
+		if (ret == -EAGAIN) {
+			work_todo = true;
+			ret = 0;
+		}
+
+		trace_scoutfs_orphan_scan_end(sb, ino, ret);
 	}
 
 	ret = 0;
@@ -2144,6 +2192,11 @@ out:
 	if (ret < 0)
 		scoutfs_inc_counter(sb, orphan_scan_error);
 
+	if (!work_todo)
+		scoutfs_inc_counter(sb, orphan_scan_empty);
+
+	trace_scoutfs_orphan_scan_stop(sb, work_todo);
+
 	scoutfs_inode_schedule_orphan_dwork(sb);
 }
 

kmod/src/msg.h

@@ -35,6 +35,12 @@ do {									\
 	}								\
 } while (0)								\
 
+#define scoutfs_bug_on_err(sb, err, fmt, args...) \
+do { \
+	__typeof__(err) _err = (err); \
+	scoutfs_bug_on(sb, _err < 0 && _err != -ENOLINK, fmt, ##args); \
+} while (0)
+
 /*
  * Each message is only generated once per volume.  Remounting resets
  * the messages.

kmod/src/options.c

@@ -33,6 +33,7 @@ enum {
 	Opt_acl,
 	Opt_data_prealloc_blocks,
 	Opt_data_prealloc_contig_only,
+	Opt_ino_alloc_per_lock,
 	Opt_log_merge_wait_timeout_ms,
 	Opt_metadev_path,
 	Opt_noacl,
@@ -47,6 +48,7 @@ static const match_table_t tokens = {
 	{Opt_acl, "acl"},
 	{Opt_data_prealloc_blocks, "data_prealloc_blocks=%s"},
 	{Opt_data_prealloc_contig_only, "data_prealloc_contig_only=%s"},
+	{Opt_ino_alloc_per_lock, "ino_alloc_per_lock=%s"},
 	{Opt_log_merge_wait_timeout_ms, "log_merge_wait_timeout_ms=%s"},
 	{Opt_metadev_path, "metadev_path=%s"},
 	{Opt_noacl, "noacl"},
@@ -136,6 +138,7 @@ static void init_default_options(struct scoutfs_mount_options *opts)
 
 	opts->data_prealloc_blocks = SCOUTFS_DATA_PREALLOC_DEFAULT_BLOCKS;
 	opts->data_prealloc_contig_only = 1;
+	opts->ino_alloc_per_lock = SCOUTFS_LOCK_INODE_GROUP_NR;
 	opts->log_merge_wait_timeout_ms = DEFAULT_LOG_MERGE_WAIT_TIMEOUT_MS;
 	opts->orphan_scan_delay_ms = -1;
 	opts->quorum_heartbeat_timeout_ms = SCOUTFS_QUORUM_DEF_HB_TIMEO_MS;
@@ -238,6 +241,18 @@ static int parse_options(struct super_block *sb, char *options, struct scoutfs_m
 			opts->data_prealloc_contig_only = nr;
 			break;
 
+		case Opt_ino_alloc_per_lock:
+			ret = match_int(args, &nr);
+			if (ret < 0 || nr < 1 || nr > SCOUTFS_LOCK_INODE_GROUP_NR) {
+				scoutfs_err(sb, "invalid ino_alloc_per_lock option, must be between 1 and %u",
+					    SCOUTFS_LOCK_INODE_GROUP_NR);
+				if (ret == 0)
+					ret = -EINVAL;
+				return ret;
+			}
+			opts->ino_alloc_per_lock = nr;
+			break;
+
 		case Opt_tcp_keepalive_timeout_ms:
 			ret = match_int(args, &nr);
 			ret = verify_tcp_keepalive_timeout_ms(sb, ret, nr);
@@ -393,6 +408,7 @@ int scoutfs_options_show(struct seq_file *seq, struct dentry *root)
 		seq_puts(seq, ",acl");
 	seq_printf(seq, ",data_prealloc_blocks=%llu", opts.data_prealloc_blocks);
 	seq_printf(seq, ",data_prealloc_contig_only=%u", opts.data_prealloc_contig_only);
+	seq_printf(seq, ",ino_alloc_per_lock=%u", opts.ino_alloc_per_lock);
 	seq_printf(seq, ",metadev_path=%s", opts.metadev_path);
 	if (!is_acl)
 		seq_puts(seq, ",noacl");
@@ -481,6 +497,45 @@ static ssize_t data_prealloc_contig_only_store(struct kobject *kobj, struct kobj
 }
 SCOUTFS_ATTR_RW(data_prealloc_contig_only);
 
+static ssize_t ino_alloc_per_lock_show(struct kobject *kobj, struct kobj_attribute *attr,
+					 char *buf)
+{
+	struct super_block *sb = SCOUTFS_SYSFS_ATTRS_SB(kobj);
+	struct scoutfs_mount_options opts;
+
+	scoutfs_options_read(sb, &opts);
+
+	return snprintf(buf, PAGE_SIZE, "%u", opts.ino_alloc_per_lock);
+}
+static ssize_t ino_alloc_per_lock_store(struct kobject *kobj, struct kobj_attribute *attr,
+					  const char *buf, size_t count)
+{
+	struct super_block *sb = SCOUTFS_SYSFS_ATTRS_SB(kobj);
+	DECLARE_OPTIONS_INFO(sb, optinf);
+	char nullterm[20]; /* more than enough for octal -U32_MAX */
+	long val;
+	int len;
+	int ret;
+
+	len = min(count, sizeof(nullterm) - 1);
+	memcpy(nullterm, buf, len);
+	nullterm[len] = '\0';
+
+	ret = kstrtol(nullterm, 0, &val);
+	if (ret < 0 || val < 1 || val > SCOUTFS_LOCK_INODE_GROUP_NR) {
+		scoutfs_err(sb, "invalid ino_alloc_per_lock option, must be between 1 and %u",
+			    SCOUTFS_LOCK_INODE_GROUP_NR);
+		return -EINVAL;
+	}
+
+	write_seqlock(&optinf->seqlock);
+	optinf->opts.ino_alloc_per_lock = val;
+	write_sequnlock(&optinf->seqlock);
+
+	return count;
+}
+SCOUTFS_ATTR_RW(ino_alloc_per_lock);
+
 static ssize_t log_merge_wait_timeout_ms_show(struct kobject *kobj, struct kobj_attribute *attr,
 						char *buf)
 {
@@ -621,6 +676,7 @@ SCOUTFS_ATTR_RO(quorum_slot_nr);
 static struct attribute *options_attrs[] = {
 	SCOUTFS_ATTR_PTR(data_prealloc_blocks),
 	SCOUTFS_ATTR_PTR(data_prealloc_contig_only),
+	SCOUTFS_ATTR_PTR(ino_alloc_per_lock),
 	SCOUTFS_ATTR_PTR(log_merge_wait_timeout_ms),
 	SCOUTFS_ATTR_PTR(metadev_path),
 	SCOUTFS_ATTR_PTR(orphan_scan_delay_ms),

kmod/src/options.h

@@ -8,6 +8,7 @@
 struct scoutfs_mount_options {
 	u64 data_prealloc_blocks;
 	bool data_prealloc_contig_only;
+	unsigned int ino_alloc_per_lock;
 	unsigned int log_merge_wait_timeout_ms;
 	char *metadev_path;
 	unsigned int orphan_scan_delay_ms;

kmod/src/scoutfs_trace.h

@@ -789,6 +789,80 @@ TRACE_EVENT(scoutfs_inode_walk_writeback,
 		  __entry->ino, __entry->write, __entry->ret)
 );
 
+TRACE_EVENT(scoutfs_orphan_scan_start,
+	TP_PROTO(struct super_block *sb),
+
+	TP_ARGS(sb),
+
+	TP_STRUCT__entry(
+		SCSB_TRACE_FIELDS
+	),
+
+	TP_fast_assign(
+		SCSB_TRACE_ASSIGN(sb);
+	),
+
+	TP_printk(SCSBF, SCSB_TRACE_ARGS)
+);
+
+TRACE_EVENT(scoutfs_orphan_scan_stop,
+	TP_PROTO(struct super_block *sb, bool work_todo),
+
+	TP_ARGS(sb, work_todo),
+
+	TP_STRUCT__entry(
+		SCSB_TRACE_FIELDS
+		__field(bool, work_todo)
+	),
+
+	TP_fast_assign(
+		SCSB_TRACE_ASSIGN(sb);
+		__entry->work_todo = work_todo;
+	),
+
+	TP_printk(SCSBF" work_todo %d", SCSB_TRACE_ARGS, __entry->work_todo)
+);
+
+TRACE_EVENT(scoutfs_orphan_scan_work,
+	TP_PROTO(struct super_block *sb, __u64 ino),
+
+	TP_ARGS(sb, ino),
+
+	TP_STRUCT__entry(
+		SCSB_TRACE_FIELDS
+		__field(__u64, ino)
+	),
+
+	TP_fast_assign(
+		SCSB_TRACE_ASSIGN(sb);
+		__entry->ino = ino;
+	),
+
+	TP_printk(SCSBF" ino %llu", SCSB_TRACE_ARGS,
+		  __entry->ino)
+);
+
+TRACE_EVENT(scoutfs_orphan_scan_end,
+	TP_PROTO(struct super_block *sb, __u64 ino, int ret),
+
+	TP_ARGS(sb, ino, ret),
+
+	TP_STRUCT__entry(
+		SCSB_TRACE_FIELDS
+		__field(__u64, ino)
+		__field(int, ret)
+	),
+
+	TP_fast_assign(
+		SCSB_TRACE_ASSIGN(sb);
+		__entry->ino = ino;
+		__entry->ret = ret;
+	),
+
+	TP_printk(SCSBF" ino %llu ret %d", SCSB_TRACE_ARGS,
+		  __entry->ino, __entry->ret)
+);
+
 DECLARE_EVENT_CLASS(scoutfs_lock_info_class,
 	TP_PROTO(struct super_block *sb, struct lock_info *linfo),
 
@@ -1036,6 +1110,82 @@ TRACE_EVENT(scoutfs_orphan_inode,
 		  MINOR(__entry->dev), __entry->ino)
 );
 
+DECLARE_EVENT_CLASS(scoutfs_try_delete_class,
+        TP_PROTO(struct super_block *sb, u64 ino),
+        TP_ARGS(sb, ino),
+        TP_STRUCT__entry(
+		SCSB_TRACE_FIELDS
+		__field(__u64, ino)
+        ),
+        TP_fast_assign(
+		SCSB_TRACE_ASSIGN(sb);
+		__entry->ino = ino;
+        ),
+	TP_printk(SCSBF" ino %llu", SCSB_TRACE_ARGS, __entry->ino)
+);
+
+DEFINE_EVENT(scoutfs_try_delete_class, scoutfs_try_delete,
+        TP_PROTO(struct super_block *sb, u64 ino),
+        TP_ARGS(sb, ino)
+);
+
+DEFINE_EVENT(scoutfs_try_delete_class, scoutfs_try_delete_local_busy,
+        TP_PROTO(struct super_block *sb, u64 ino),
+        TP_ARGS(sb, ino)
+);
+
+DEFINE_EVENT(scoutfs_try_delete_class, scoutfs_try_delete_cached,
+        TP_PROTO(struct super_block *sb, u64 ino),
+        TP_ARGS(sb, ino)
+);
+
+DEFINE_EVENT(scoutfs_try_delete_class, scoutfs_try_delete_no_item,
+        TP_PROTO(struct super_block *sb, u64 ino),
+        TP_ARGS(sb, ino)
+);
+
+TRACE_EVENT(scoutfs_try_delete_has_links,
+	TP_PROTO(struct super_block *sb, u64 ino, unsigned int nlink),
+
+	TP_ARGS(sb, ino, nlink),
+
+	TP_STRUCT__entry(
+		SCSB_TRACE_FIELDS
+		__field(__u64, ino)
+		__field(unsigned int, nlink)
+	),
+
+	TP_fast_assign(
+		SCSB_TRACE_ASSIGN(sb);
+		__entry->ino = ino;
+		__entry->nlink = nlink;
+	),
+
+	TP_printk(SCSBF" ino %llu nlink %u", SCSB_TRACE_ARGS, __entry->ino,
+		  __entry->nlink)
+);
+
+TRACE_EVENT(scoutfs_inode_orphan_delete,
+	TP_PROTO(struct super_block *sb, u64 ino, int ret),
+
+	TP_ARGS(sb, ino, ret),
+
+	TP_STRUCT__entry(
+		SCSB_TRACE_FIELDS
+		__field(__u64, ino)
+		__field(int, ret)
+	),
+
+	TP_fast_assign(
+		SCSB_TRACE_ASSIGN(sb);
+		__entry->ino = ino;
+		__entry->ret = ret;
+	),
+
+	TP_printk(SCSBF" ino %llu ret %d", SCSB_TRACE_ARGS, __entry->ino,
+		__entry->ret)
+);
+
 TRACE_EVENT(scoutfs_delete_inode,
 	TP_PROTO(struct super_block *sb, u64 ino, umode_t mode, u64 size),
 
@@ -1060,6 +1210,32 @@ TRACE_EVENT(scoutfs_delete_inode,
 		  __entry->mode, __entry->size)
 );
 
+TRACE_EVENT(scoutfs_delete_inode_end,
+	TP_PROTO(struct super_block *sb, u64 ino, umode_t mode, u64 size, int ret),
+
+	TP_ARGS(sb, ino, mode, size, ret),
+
+	TP_STRUCT__entry(
+		__field(dev_t, dev)
+		__field(__u64, ino)
+		__field(umode_t, mode)
+		__field(__u64, size)
+		__field(int, ret)
+	),
+
+	TP_fast_assign(
+		__entry->dev = sb->s_dev;
+		__entry->ino = ino;
+		__entry->mode = mode;
+		__entry->size = size;
+		__entry->ret = ret;
+	),
+
+	TP_printk("dev %d,%d ino %llu, mode 0x%x size %llu, ret %d",
+		  MAJOR(__entry->dev), MINOR(__entry->dev), __entry->ino,
+		  __entry->mode, __entry->size, __entry->ret)
+);
+
 DECLARE_EVENT_CLASS(scoutfs_key_class,
         TP_PROTO(struct super_block *sb, struct scoutfs_key *key),
         TP_ARGS(sb, key),
@@ -2466,24 +2642,39 @@ TRACE_EVENT(scoutfs_block_dirty_ref,
 );
 
 TRACE_EVENT(scoutfs_get_file_block,
-	TP_PROTO(struct super_block *sb, u64 blkno, int flags),
+	TP_PROTO(struct super_block *sb, u64 blkno, int flags,
+		 struct scoutfs_srch_block *srb),
 
-	TP_ARGS(sb, blkno, flags),
+	TP_ARGS(sb, blkno, flags, srb),
 
 	TP_STRUCT__entry(
 		SCSB_TRACE_FIELDS
 		__field(__u64, blkno)
 		__field(int, flags)
+		__field(__u64, first_hash)
+		__field(__u64, first_ino)
+		__field(__u64, first_id)
+		__field(__u64, last_hash)
+		__field(__u64, last_ino)
+		__field(__u64, last_id)
 	),
 
 	TP_fast_assign(
 		SCSB_TRACE_ASSIGN(sb);
 		__entry->blkno = blkno;
 		__entry->flags = flags;
+		__entry->first_hash = __le64_to_cpu(srb->first.hash);
+		__entry->first_ino = __le64_to_cpu(srb->first.ino);
+		__entry->first_id = __le64_to_cpu(srb->first.id);
+		__entry->last_hash = __le64_to_cpu(srb->last.hash);
+		__entry->last_ino = __le64_to_cpu(srb->last.ino);
+		__entry->last_id = __le64_to_cpu(srb->last.id);
 	),
 
-	TP_printk(SCSBF" blkno %llu flags 0x%x",
-		  SCSB_TRACE_ARGS, __entry->blkno, __entry->flags)
+	TP_printk(SCSBF" blkno %llu flags 0x%x first_hash 0x%llx first_ino %llu fist_id 0x%llx last_hash 0x%llx last_ino %llu last_id 0x%llx",
+		  SCSB_TRACE_ARGS, __entry->blkno, __entry->flags,
+		  __entry->first_hash, __entry->first_ino, __entry->first_id,
+		  __entry->last_hash, __entry->last_ino, __entry->last_id)
 );
 
 TRACE_EVENT(scoutfs_block_stale,
@@ -3097,6 +3288,24 @@ TRACE_EVENT(scoutfs_ioc_search_xattrs,
 		  __entry->ino, __entry->last_ino)
 );
 
+TRACE_EVENT(scoutfs_trigger_fired,
+	TP_PROTO(struct super_block *sb, const char *name),
+
+	TP_ARGS(sb, name),
+
+	TP_STRUCT__entry(
+		SCSB_TRACE_FIELDS
+		__field(const char *, name)
+	),
+
+	TP_fast_assign(
+		SCSB_TRACE_ASSIGN(sb);
+		__entry->name = name;
+	),
+
+	TP_printk(SCSBF" %s", SCSB_TRACE_ARGS, __entry->name)
+);
+
 #endif /* _TRACE_SCOUTFS_H */
 
 /* This part must be outside protection */

kmod/src/server.c

@@ -41,6 +41,7 @@
 #include "recov.h"
 #include "omap.h"
 #include "fence.h"
+#include "triggers.h"
 
 /*
  * Every active mount can act as the server that listens on a net
@@ -994,10 +995,11 @@ static int for_each_rid_last_lt(struct super_block *sb, struct scoutfs_btree_roo
 }
 
 /*
- * Log merge range items are stored at the starting fs key of the range.
- * The only fs key field that doesn't hold information is the zone, so
- * we use the zone to differentiate all types that we store in the log
- * merge tree.
+ * Log merge range items are stored at the starting fs key of the range
+ * with the zone overwritten to indicate the log merge item type.  This
+ * day0 mistake loses sorting information for items in the different
+ * zones in the fs root, so the range items aren't strictly sorted by
+ * the starting key of their range.
  */
 static void init_log_merge_key(struct scoutfs_key *key, u8 zone, u64 first,
 			       u64 second)
@@ -1029,6 +1031,51 @@ static int next_log_merge_item_key(struct super_block *sb, struct scoutfs_btree_
 	return ret;
 }
 
+/*
+ * The range items aren't sorted by their range.start because
+ * _RANGE_ZONE clobbers the range's zone.  We sweep all the items and
+ * find the range with the next least starting key that's greater than
+ * the caller's starting key.  We have to be careful to iterate over the
+ * log_merge tree keys because the ranges can overlap as they're mapped
+ * to the log_merge keys by clobbering their zone.
+ */
+static int next_log_merge_range(struct super_block *sb, struct scoutfs_btree_root *root,
+				struct scoutfs_key *start, struct scoutfs_log_merge_range *rng)
+{
+	struct scoutfs_log_merge_range *next;
+	SCOUTFS_BTREE_ITEM_REF(iref);
+	struct scoutfs_key key;
+	int ret;
+
+	key = *start;
+	key.sk_zone = SCOUTFS_LOG_MERGE_RANGE_ZONE;
+	scoutfs_key_set_ones(&rng->start);
+
+	do {
+		ret = scoutfs_btree_next(sb, root, &key, &iref);
+		if (ret == 0) {
+			if (iref.key->sk_zone != SCOUTFS_LOG_MERGE_RANGE_ZONE) {
+				ret = -ENOENT;
+			} else if (iref.val_len != sizeof(struct scoutfs_log_merge_range)) {
+				ret = -EIO;
+			} else {
+				next = iref.val;
+				if (scoutfs_key_compare(&next->start, &rng->start) < 0 &&
+				    scoutfs_key_compare(&next->start, start) >= 0)
+					*rng = *next;
+				key = *iref.key;
+				scoutfs_key_inc(&key);
+			}
+			scoutfs_btree_put_iref(&iref);
+		}
+	} while (ret == 0);
+
+	if (ret == -ENOENT && !scoutfs_key_is_ones(&rng->start))
+		ret = 0;
+
+	return ret;
+}
+
 static int next_log_merge_item(struct super_block *sb,
 			       struct scoutfs_btree_root *root,
 			       u8 zone, u64 first, u64 second,
@@ -1245,9 +1292,13 @@ static int finalize_and_start_log_merge(struct super_block *sb, struct scoutfs_l
 		 * meta was low so that deleted items are merged
 		 * promptly and freed blocks can bring the client out of
 		 * enospc.
+		 *
+		 * The trigger can be used to force a log merge in cases where
+		 * a test only generates small amounts of change.
 		 */
 		finalize_ours = (lt->item_root.height > 2) ||
-				(le32_to_cpu(lt->meta_avail.flags) & SCOUTFS_ALLOC_FLAG_LOW);
+				(le32_to_cpu(lt->meta_avail.flags) & SCOUTFS_ALLOC_FLAG_LOW) ||
+				scoutfs_trigger(sb, LOG_MERGE_FORCE_FINALIZE_OURS);
 
 		trace_scoutfs_server_finalize_decision(sb, rid, saw_finalized, others_active,
 						       ours_visible, finalize_ours, delay_ms,
@@ -1356,6 +1407,8 @@ static int finalize_and_start_log_merge(struct super_block *sb, struct scoutfs_l
 			BUG_ON(err); /* inconsistent */
 		}
 
+		scoutfs_inc_counter(sb, log_merge_start);
+
 		/* we're done, caller can make forward progress */
 		break;
 	}
@@ -1572,7 +1625,8 @@ static int server_get_log_trees(struct super_block *sb,
 		goto update;
 	}
 
-	ret = alloc_move_empty(sb, &super->data_alloc, &lt.data_freed, 100);
+	ret = alloc_move_empty(sb, &super->data_alloc, &lt.data_freed,
+			       COMMIT_HOLD_ALLOC_BUDGET / 2);
 	if (ret == -EINPROGRESS)
 		ret = 0;
 	if (ret < 0) {
@@ -1682,6 +1736,7 @@ static int server_commit_log_trees(struct super_block *sb,
 	int ret;
 
 	if (arg_len != sizeof(struct scoutfs_log_trees)) {
+		err_str = "invalid message log_trees size";
 		ret = -EINVAL;
 		goto out;
 	}
@@ -1745,7 +1800,7 @@ static int server_commit_log_trees(struct super_block *sb,
 
 	ret = scoutfs_btree_update(sb, &server->alloc, &server->wri,
 				   &super->logs_root, &key, &lt, sizeof(lt));
-	BUG_ON(ret < 0); /* dirtying should have guaranteed success */
+	BUG_ON(ret < 0); /* dirtying should have guaranteed success, srch item inconsistent */
 	if (ret < 0)
 		err_str = "updating log trees item";
 
@@ -1753,11 +1808,10 @@ unlock:
 	mutex_unlock(&server->logs_mutex);
 
 	ret = server_apply_commit(sb, &hold, ret);
+out:
 	if (ret < 0)
 		scoutfs_err(sb, "server error %d committing client logs for rid %016llx, nr %llu: %s",
 			    ret, rid, le64_to_cpu(lt.nr), err_str);
-out:
-	WARN_ON_ONCE(ret < 0);
 	return scoutfs_net_response(sb, conn, cmd, id, ret, NULL, 0);
 }
 
@@ -1867,9 +1921,11 @@ static int reclaim_open_log_tree(struct super_block *sb, u64 rid)
 	       scoutfs_alloc_splice_list(sb, &server->alloc, &server->wri, server->other_freed,
 					 &lt.meta_avail)) ?:
 	      (err_str = "empty data_avail",
-	       alloc_move_empty(sb, &super->data_alloc, &lt.data_avail, 100)) ?:
+	       alloc_move_empty(sb, &super->data_alloc, &lt.data_avail,
+				COMMIT_HOLD_ALLOC_BUDGET / 2)) ?:
 	      (err_str = "empty data_freed",
-	       alloc_move_empty(sb, &super->data_alloc, &lt.data_freed, 100));
+	       alloc_move_empty(sb, &super->data_alloc, &lt.data_freed,
+				COMMIT_HOLD_ALLOC_BUDGET / 2));
 	mutex_unlock(&server->alloc_mutex);
 
 	/* only finalize, allowing merging, once the allocators are fully freed */
@@ -2094,7 +2150,7 @@ static int server_srch_get_compact(struct super_block *sb,
 
 apply:
 	ret = server_apply_commit(sb, &hold, ret);
-	WARN_ON_ONCE(ret < 0 && ret != -ENOENT); /* XXX leaked busy item */
+	WARN_ON_ONCE(ret < 0 && ret != -ENOENT && ret != -ENOLINK); /* XXX leaked busy item */
 out:
 	ret = scoutfs_net_response(sb, conn, cmd, id, ret,
 				   sc, sizeof(struct scoutfs_srch_compact));
@@ -2460,6 +2516,8 @@ static int splice_log_merge_completions(struct super_block *sb,
 		queue_work(server->wq, &server->log_merge_free_work);
 	else
 		err_str = "deleting merge status item";
+
+	scoutfs_inc_counter(sb, log_merge_complete);
 out:
 	if (upd_stat) {
 		init_log_merge_key(&key, SCOUTFS_LOG_MERGE_STATUS_ZONE, 0, 0);
@@ -2472,10 +2530,9 @@ out:
 		}
 	}
 
-	if (ret < 0)
-		scoutfs_err(sb, "server error %d splicing log merge completion: %s", ret, err_str);
-
-	BUG_ON(ret); /* inconsistent */
+	/* inconsistent */
+	scoutfs_bug_on_err(sb, ret,
+			   "server error %d splicing log merge completion: %s", ret, err_str);
 
 	return ret ?: einprogress;
 }
@@ -2720,10 +2777,7 @@ restart:
 
 	/* find the next range, always checking for splicing */
 	for (;;) {
-		key = stat.next_range_key;
-		key.sk_zone = SCOUTFS_LOG_MERGE_RANGE_ZONE;
-		ret = next_log_merge_item_key(sb, &super->log_merge, SCOUTFS_LOG_MERGE_RANGE_ZONE,
-					      &key, &rng, sizeof(rng));
+		ret = next_log_merge_range(sb, &super->log_merge, &stat.next_range_key, &rng);
 		if (ret < 0 && ret != -ENOENT) {
 			err_str = "finding merge range item";
 			goto out;
@@ -2994,7 +3048,13 @@ static int server_commit_log_merge(struct super_block *sb,
 				  SCOUTFS_LOG_MERGE_STATUS_ZONE, 0, 0,
 				  &stat, sizeof(stat));
 	if (ret < 0) {
-		err_str = "getting merge status item";
+		/*
+		 * During a retransmission, it's possible that the server
+		 * already committed and resolved this log merge. ENOENT
+		 * is expected in that case.
+		 */
+		if (ret != -ENOENT)
+			err_str = "getting merge status item";
 		goto out;
 	}
 

kmod/src/srch.c

@@ -443,7 +443,7 @@ out:
 		sfl->blocks = cpu_to_le64(blk + 1);
 
 	if (bl) {
-		trace_scoutfs_get_file_block(sb, bl->blkno, flags);
+		trace_scoutfs_get_file_block(sb, bl->blkno, flags, bl->data);
 	}
 
 	*bl_ret = bl;
@@ -745,6 +745,7 @@ static int search_log_file(struct super_block *sb,
 		for (i = 0; i < le32_to_cpu(srb->entry_nr); i++) {
 			if (pos > SCOUTFS_SRCH_BLOCK_SAFE_BYTES) {
 				/* can only be inconsistency :/ */
+				scoutfs_err(sb, "@@@ pos %d > %ld", pos, SCOUTFS_SRCH_BLOCK_SAFE_BYTES);
 				ret = -EIO;
 				break;
 			}
@@ -752,6 +753,7 @@ static int search_log_file(struct super_block *sb,
 			ret = decode_entry(srb->entries + pos, &sre, &prev);
 			if (ret <= 0) {
 				/* can only be inconsistency :/ */
+				scoutfs_err(sb, "@@@ decode_entry -> %d", ret);
 				ret = -EIO;
 				break;
 			}
@@ -855,6 +857,7 @@ static int search_sorted_file(struct super_block *sb,
 
 		if (pos > SCOUTFS_SRCH_BLOCK_SAFE_BYTES) {
 			/* can only be inconsistency :/ */
+			scoutfs_err(sb, "@@@ 2: pos %d > %ld", pos, SCOUTFS_SRCH_BLOCK_SAFE_BYTES);
 			ret = -EIO;
 			goto out;
 		}
@@ -862,6 +865,7 @@ static int search_sorted_file(struct super_block *sb,
 		ret = decode_entry(srb->entries + pos, &sre, &prev);
 		if (ret <= 0) {
 			/* can only be inconsistency :/ */
+			scoutfs_err(sb, "@@@ 2: decode -> %d", ret);
 			ret = -EIO;
 			goto out;
 		}
@@ -1001,6 +1005,7 @@ retry:
 				scoutfs_key_inc(&key);
 				memcpy(&sfl, iref.val, iref.val_len);
 			} else {
+				scoutfs_err(sb, "@@@ btree_next bad?");
 				ret = -EIO;
 			}
 			scoutfs_btree_put_iref(&iref);
@@ -1036,6 +1041,7 @@ retry:
 				scoutfs_key_inc(&key);
 				memcpy(&lt, iref.val, iref.val_len);
 			} else {
+				scoutfs_err(sb, "@@@ btree_next bad 2");
 				ret = -EIO;
 			}
 			scoutfs_btree_put_iref(&iref);
@@ -1151,6 +1157,7 @@ int scoutfs_srch_get_compact(struct super_block *sb,
 				key = *iref.key;
 				memcpy(sc, iref.val, iref.val_len);
 			} else {
+				scoutfs_err(sb, "@@@ btree_next bad 3");
 				ret = -EIO;
 			}
 			scoutfs_btree_put_iref(&iref);
@@ -1209,6 +1216,7 @@ int scoutfs_srch_get_compact(struct super_block *sb,
 				key = *iref.key;
 				memcpy(&sfl, iref.val, iref.val_len);
 			} else {
+				scoutfs_err(sb, "@@@ btree_next bad 4");
 				ret = -EIO;
 			}
 			scoutfs_btree_put_iref(&iref);
@@ -1402,8 +1410,10 @@ int scoutfs_srch_commit_compact(struct super_block *sb,
 	if (ret == 0) {
 		if (iref.val_len == sizeof(struct scoutfs_srch_compact))
 			memcpy(busy, iref.val, iref.val_len);
-		else
+		else {
+			scoutfs_err(sb, "@@@ btree_lookup bad");
 			ret = -EIO;
+		}
 		scoutfs_btree_put_iref(&iref);
 	}
 	if (ret < 0)
@@ -1496,6 +1506,7 @@ int scoutfs_srch_cancel_compact(struct super_block *sb,
 		if (scoutfs_key_compare(iref.key, &last) > 0) {
 			ret = -ENOENT;
 		} else if (iref.val_len != sizeof(*sc)) {
+			scoutfs_err(sb, "@@@ btree_next bad 5");
 			ret = -EIO;
 		} else {
 			key = *iref.key;
@@ -1637,6 +1648,7 @@ static int kway_merge(struct super_block *sb,
 					   &root->sre, &srb->tail);
 			if (WARN_ON_ONCE(ret <= 0)) {
 				/* shouldn't happen */
+				scoutfs_err(sb, "@@@ encode -> %d", ret);
 				ret = -EIO;
 				goto out;
 			}
@@ -1861,6 +1873,7 @@ static int compact_logs(struct super_block *sb,
 
 		if (pos > SCOUTFS_SRCH_BLOCK_SAFE_BYTES) {
 			/* can only be inconsistency :/ */
+			scoutfs_err(sb, "@@@ 3: pos %d > %ld", pos, SCOUTFS_SRCH_BLOCK_SAFE_BYTES);
 			ret = -EIO;
 			goto out;
 		}
@@ -1868,6 +1881,7 @@ static int compact_logs(struct super_block *sb,
 		ret = decode_entry(srb->entries + pos, sre, &prev);
 		if (ret <= 0) {
 			/* can only be inconsistency :/ */
+			scoutfs_err(sb, "@@@ new decode -> %d", ret);
 			ret = -EIO;
 			goto out;
 		}
@@ -1982,6 +1996,10 @@ static int kway_get_reader(struct super_block *sb,
 	    rdr->skip > SCOUTFS_SRCH_BLOCK_SAFE_BYTES ||
 	    rdr->skip >= le32_to_cpu(srb->entry_bytes)) {
 		/* XXX inconsistency */
+		scoutfs_err(sb, "@@@ pos %u vs %ld, skip %u , %u",
+			rdr->pos, SCOUTFS_SRCH_BLOCK_SAFE_BYTES,
+			rdr->skip,
+			le32_to_cpu(srb->entry_bytes));
 		return -EIO;
 	}
 
@@ -1997,6 +2015,7 @@ static int kway_get_reader(struct super_block *sb,
 				   &rdr->decoded_sre, &rdr->prev);
 		if (ret <= 0) {
 			/* XXX inconsistency */
+			scoutfs_err(sb, "@@@ decode new2 ret %d", ret);
 			return -EIO;
 		}
 
@@ -2293,8 +2312,10 @@ static void scoutfs_srch_compact_worker(struct work_struct *work)
 out:
 	/* our allocators and files should be stable */
 	WARN_ON_ONCE(ret == -ESTALE);
-	if (ret < 0)
+	if (ret < 0) {
+		scoutfs_err(sb, "@@@ srch_compact_error %d", ret);
 		scoutfs_inc_counter(sb, srch_compact_error);
+	}
 
 	scoutfs_block_writer_forget_all(sb, &wri);
 	queue_compact_work(srinf, sc != NULL && sc->nr > 0 && ret == 0);

kmod/src/triggers.c

@@ -18,6 +18,7 @@
 
 #include "super.h"
 #include "triggers.h"
+#include "scoutfs_trace.h"
 
 /*
  * We have debugfs files we can write to which arm triggers which
@@ -39,6 +40,7 @@ struct scoutfs_triggers {
 
 static char *names[] = {
 	[SCOUTFS_TRIGGER_BLOCK_REMOVE_STALE] = "block_remove_stale",
+	[SCOUTFS_TRIGGER_LOG_MERGE_FORCE_FINALIZE_OURS] = "log_merge_force_finalize_ours",
 	[SCOUTFS_TRIGGER_SRCH_COMPACT_LOGS_PAD_SAFE] = "srch_compact_logs_pad_safe",
 	[SCOUTFS_TRIGGER_SRCH_FORCE_LOG_ROTATE] = "srch_force_log_rotate",
 	[SCOUTFS_TRIGGER_SRCH_MERGE_STOP_SAFE] = "srch_merge_stop_safe",
@@ -51,6 +53,7 @@ bool scoutfs_trigger_test_and_clear(struct super_block *sb, unsigned int t)
 	atomic_t *atom;
 	int old;
 	int mem;
+	bool fired;
 
 	BUG_ON(t >= SCOUTFS_TRIGGER_NR);
 	atom = &triggers->atomics[t];
@@ -64,7 +67,12 @@ bool scoutfs_trigger_test_and_clear(struct super_block *sb, unsigned int t)
 		mem = atomic_cmpxchg(atom, old, 0);
 	} while (mem && mem != old);
 
-	return !!mem;
+	fired = !!mem;
+
+	if (fired)
+		trace_scoutfs_trigger_fired(sb, names[t]);
+
+	return fired;
 }
 
 int scoutfs_setup_triggers(struct super_block *sb)

kmod/src/triggers.h

@@ -3,6 +3,7 @@
 
 enum scoutfs_trigger {
 	SCOUTFS_TRIGGER_BLOCK_REMOVE_STALE,
+	SCOUTFS_TRIGGER_LOG_MERGE_FORCE_FINALIZE_OURS,
 	SCOUTFS_TRIGGER_SRCH_COMPACT_LOGS_PAD_SAFE,
 	SCOUTFS_TRIGGER_SRCH_FORCE_LOG_ROTATE,
 	SCOUTFS_TRIGGER_SRCH_MERGE_STOP_SAFE,

tests/README.md

@@ -117,6 +117,7 @@ used during the test.
 | T\_NR\_MOUNTS    | number of mounts     | -n              | 3                 |
 | T\_O[0-9]        | mount options        | created per run | -o server\_addr=  |
 | T\_QUORUM        | quorum count         | -q              | 2                 |
+| T\_EXTRA         | per-test file dir    | revision ctled  | tests/extra/t     |
 | T\_TMP           | per-test tmp prefix  | made for test   | results/tmp/t/tmp |
 | T\_TMPDIR        | per-test tmp dir dir | made for test   | results/tmp/t     |
 

tests/extra/xfstests/expected-results

@@ -0,0 +1,882 @@
+Ran:
+generic/001
+generic/002
+generic/004
+generic/005
+generic/006
+generic/007
+generic/008
+generic/009
+generic/011
+generic/012
+generic/013
+generic/014
+generic/015
+generic/016
+generic/018
+generic/020
+generic/021
+generic/022
+generic/023
+generic/024
+generic/025
+generic/026
+generic/028
+generic/029
+generic/030
+generic/031
+generic/032
+generic/033
+generic/034
+generic/035
+generic/037
+generic/039
+generic/040
+generic/041
+generic/050
+generic/052
+generic/053
+generic/056
+generic/057
+generic/058
+generic/059
+generic/060
+generic/061
+generic/062
+generic/063
+generic/064
+generic/065
+generic/066
+generic/067
+generic/069
+generic/070
+generic/071
+generic/073
+generic/076
+generic/078
+generic/079
+generic/080
+generic/081
+generic/082
+generic/084
+generic/086
+generic/087
+generic/088
+generic/090
+generic/091
+generic/092
+generic/094
+generic/096
+generic/097
+generic/098
+generic/099
+generic/101
+generic/104
+generic/105
+generic/106
+generic/107
+generic/110
+generic/111
+generic/113
+generic/114
+generic/115
+generic/116
+generic/117
+generic/118
+generic/119
+generic/120
+generic/121
+generic/122
+generic/123
+generic/124
+generic/126
+generic/128
+generic/129
+generic/130
+generic/131
+generic/134
+generic/135
+generic/136
+generic/138
+generic/139
+generic/140
+generic/141
+generic/142
+generic/143
+generic/144
+generic/145
+generic/146
+generic/147
+generic/148
+generic/149
+generic/150
+generic/151
+generic/152
+generic/153
+generic/154
+generic/155
+generic/156
+generic/157
+generic/158
+generic/159
+generic/160
+generic/161
+generic/162
+generic/163
+generic/169
+generic/171
+generic/172
+generic/173
+generic/174
+generic/177
+generic/178
+generic/179
+generic/180
+generic/181
+generic/182
+generic/183
+generic/184
+generic/185
+generic/188
+generic/189
+generic/190
+generic/191
+generic/193
+generic/194
+generic/195
+generic/196
+generic/197
+generic/198
+generic/199
+generic/200
+generic/201
+generic/202
+generic/203
+generic/205
+generic/206
+generic/207
+generic/210
+generic/211
+generic/212
+generic/214
+generic/215
+generic/216
+generic/217
+generic/218
+generic/219
+generic/220
+generic/221
+generic/222
+generic/223
+generic/225
+generic/227
+generic/228
+generic/229
+generic/230
+generic/235
+generic/236
+generic/237
+generic/238
+generic/240
+generic/244
+generic/245
+generic/246
+generic/247
+generic/248
+generic/249
+generic/250
+generic/252
+generic/253
+generic/254
+generic/255
+generic/256
+generic/257
+generic/258
+generic/259
+generic/260
+generic/261
+generic/262
+generic/263
+generic/264
+generic/265
+generic/266
+generic/267
+generic/268
+generic/271
+generic/272
+generic/276
+generic/277
+generic/278
+generic/279
+generic/281
+generic/282
+generic/283
+generic/284
+generic/286
+generic/287
+generic/288
+generic/289
+generic/290
+generic/291
+generic/292
+generic/293
+generic/294
+generic/295
+generic/296
+generic/301
+generic/302
+generic/303
+generic/304
+generic/305
+generic/306
+generic/307
+generic/308
+generic/309
+generic/312
+generic/313
+generic/314
+generic/315
+generic/316
+generic/317
+generic/319
+generic/322
+generic/324
+generic/325
+generic/326
+generic/327
+generic/328
+generic/329
+generic/330
+generic/331
+generic/332
+generic/335
+generic/336
+generic/337
+generic/341
+generic/342
+generic/343
+generic/346
+generic/348
+generic/353
+generic/355
+generic/358
+generic/359
+generic/360
+generic/361
+generic/362
+generic/363
+generic/364
+generic/365
+generic/366
+generic/367
+generic/368
+generic/369
+generic/370
+generic/371
+generic/372
+generic/373
+generic/374
+generic/375
+generic/376
+generic/377
+generic/378
+generic/379
+generic/380
+generic/381
+generic/382
+generic/383
+generic/384
+generic/385
+generic/386
+generic/389
+generic/391
+generic/392
+generic/393
+generic/394
+generic/395
+generic/396
+generic/397
+generic/398
+generic/400
+generic/401
+generic/402
+generic/403
+generic/404
+generic/406
+generic/407
+generic/408
+generic/412
+generic/413
+generic/414
+generic/417
+generic/419
+generic/420
+generic/421
+generic/422
+generic/424
+generic/425
+generic/426
+generic/427
+generic/428
+generic/436
+generic/437
+generic/439
+generic/440
+generic/443
+generic/445
+generic/446
+generic/448
+generic/449
+generic/450
+generic/451
+generic/452
+generic/453
+generic/454
+generic/456
+generic/458
+generic/460
+generic/462
+generic/463
+generic/465
+generic/466
+generic/468
+generic/469
+generic/470
+generic/471
+generic/474
+generic/477
+generic/478
+generic/479
+generic/480
+generic/481
+generic/483
+generic/485
+generic/486
+generic/487
+generic/488
+generic/489
+generic/490
+generic/491
+generic/492
+generic/498
+generic/499
+generic/501
+generic/502
+generic/503
+generic/504
+generic/505
+generic/506
+generic/507
+generic/508
+generic/509
+generic/510
+generic/511
+generic/512
+generic/513
+generic/514
+generic/515
+generic/516
+generic/517
+generic/518
+generic/519
+generic/520
+generic/523
+generic/524
+generic/525
+generic/526
+generic/527
+generic/528
+generic/529
+generic/530
+generic/531
+generic/533
+generic/534
+generic/535
+generic/536
+generic/537
+generic/538
+generic/539
+generic/540
+generic/541
+generic/542
+generic/543
+generic/544
+generic/545
+generic/546
+generic/547
+generic/548
+generic/549
+generic/550
+generic/552
+generic/553
+generic/555
+generic/556
+generic/557
+generic/566
+generic/567
+generic/571
+generic/572
+generic/573
+generic/574
+generic/575
+generic/576
+generic/577
+generic/578
+generic/580
+generic/581
+generic/582
+generic/583
+generic/584
+generic/586
+generic/587
+generic/588
+generic/591
+generic/592
+generic/593
+generic/594
+generic/595
+generic/596
+generic/597
+generic/598
+generic/599
+generic/600
+generic/601
+generic/602
+generic/603
+generic/604
+generic/605
+generic/606
+generic/607
+generic/608
+generic/609
+generic/610
+generic/611
+generic/612
+generic/613
+generic/614
+generic/618
+generic/621
+generic/623
+generic/624
+generic/625
+generic/626
+generic/628
+generic/629
+generic/630
+generic/632
+generic/634
+generic/635
+generic/637
+generic/638
+generic/639
+generic/640
+generic/644
+generic/645
+generic/646
+generic/647
+generic/651
+generic/652
+generic/653
+generic/654
+generic/655
+generic/657
+generic/658
+generic/659
+generic/660
+generic/661
+generic/662
+generic/663
+generic/664
+generic/665
+generic/666
+generic/667
+generic/668
+generic/669
+generic/673
+generic/674
+generic/675
+generic/676
+generic/677
+generic/678
+generic/679
+generic/680
+generic/681
+generic/682
+generic/683
+generic/684
+generic/685
+generic/686
+generic/687
+generic/688
+generic/689
+shared/002
+shared/032
+Not
+run:
+generic/008
+generic/009
+generic/012
+generic/015
+generic/016
+generic/018
+generic/021
+generic/022
+generic/025
+generic/026
+generic/031
+generic/033
+generic/050
+generic/052
+generic/058
+generic/059
+generic/060
+generic/061
+generic/063
+generic/064
+generic/078
+generic/079
+generic/081
+generic/082
+generic/091
+generic/094
+generic/096
+generic/110
+generic/111
+generic/113
+generic/114
+generic/115
+generic/116
+generic/118
+generic/119
+generic/121
+generic/122
+generic/123
+generic/128
+generic/130
+generic/134
+generic/135
+generic/136
+generic/138
+generic/139
+generic/140
+generic/142
+generic/143
+generic/144
+generic/145
+generic/146
+generic/147
+generic/148
+generic/149
+generic/150
+generic/151
+generic/152
+generic/153
+generic/154
+generic/155
+generic/156
+generic/157
+generic/158
+generic/159
+generic/160
+generic/161
+generic/162
+generic/163
+generic/171
+generic/172
+generic/173
+generic/174
+generic/177
+generic/178
+generic/179
+generic/180
+generic/181
+generic/182
+generic/183
+generic/185
+generic/188
+generic/189
+generic/190
+generic/191
+generic/193
+generic/194
+generic/195
+generic/196
+generic/197
+generic/198
+generic/199
+generic/200
+generic/201
+generic/202
+generic/203
+generic/205
+generic/206
+generic/207
+generic/210
+generic/211
+generic/212
+generic/214
+generic/216
+generic/217
+generic/218
+generic/219
+generic/220
+generic/222
+generic/223
+generic/225
+generic/227
+generic/229
+generic/230
+generic/235
+generic/238
+generic/240
+generic/244
+generic/250
+generic/252
+generic/253
+generic/254
+generic/255
+generic/256
+generic/259
+generic/260
+generic/261
+generic/262
+generic/263
+generic/264
+generic/265
+generic/266
+generic/267
+generic/268
+generic/271
+generic/272
+generic/276
+generic/277
+generic/278
+generic/279
+generic/281
+generic/282
+generic/283
+generic/284
+generic/287
+generic/288
+generic/289
+generic/290
+generic/291
+generic/292
+generic/293
+generic/295
+generic/296
+generic/301
+generic/302
+generic/303
+generic/304
+generic/305
+generic/312
+generic/314
+generic/316
+generic/317
+generic/324
+generic/326
+generic/327
+generic/328
+generic/329
+generic/330
+generic/331
+generic/332
+generic/353
+generic/355
+generic/358
+generic/359
+generic/361
+generic/362
+generic/363
+generic/364
+generic/365
+generic/366
+generic/367
+generic/368
+generic/369
+generic/370
+generic/371
+generic/372
+generic/373
+generic/374
+generic/378
+generic/379
+generic/380
+generic/381
+generic/382
+generic/383
+generic/384
+generic/385
+generic/386
+generic/391
+generic/392
+generic/395
+generic/396
+generic/397
+generic/398
+generic/400
+generic/402
+generic/404
+generic/406
+generic/407
+generic/408
+generic/412
+generic/413
+generic/414
+generic/417
+generic/419
+generic/420
+generic/421
+generic/422
+generic/424
+generic/425
+generic/427
+generic/439
+generic/440
+generic/446
+generic/449
+generic/450
+generic/451
+generic/453
+generic/454
+generic/456
+generic/458
+generic/462
+generic/463
+generic/465
+generic/466
+generic/468
+generic/469
+generic/470
+generic/471
+generic/474
+generic/485
+generic/487
+generic/488
+generic/491
+generic/492
+generic/499
+generic/501
+generic/503
+generic/505
+generic/506
+generic/507
+generic/508
+generic/511
+generic/513
+generic/514
+generic/515
+generic/516
+generic/517
+generic/518
+generic/519
+generic/520
+generic/528
+generic/530
+generic/536
+generic/537
+generic/538
+generic/539
+generic/540
+generic/541
+generic/542
+generic/543
+generic/544
+generic/545
+generic/546
+generic/548
+generic/549
+generic/550
+generic/552
+generic/553
+generic/555
+generic/556
+generic/566
+generic/567
+generic/572
+generic/573
+generic/574
+generic/575
+generic/576
+generic/577
+generic/578
+generic/580
+generic/581
+generic/582
+generic/583
+generic/584
+generic/586
+generic/587
+generic/588
+generic/591
+generic/592
+generic/593
+generic/594
+generic/595
+generic/596
+generic/597
+generic/598
+generic/599
+generic/600
+generic/601
+generic/602
+generic/603
+generic/605
+generic/606
+generic/607
+generic/608
+generic/609
+generic/610
+generic/612
+generic/613
+generic/621
+generic/623
+generic/624
+generic/625
+generic/626
+generic/628
+generic/629
+generic/630
+generic/635
+generic/644
+generic/645
+generic/646
+generic/647
+generic/651
+generic/652
+generic/653
+generic/654
+generic/655
+generic/657
+generic/658
+generic/659
+generic/660
+generic/661
+generic/662
+generic/663
+generic/664
+generic/665
+generic/666
+generic/667
+generic/668
+generic/669
+generic/673
+generic/674
+generic/675
+generic/677
+generic/678
+generic/679
+generic/680
+generic/681
+generic/682
+generic/683
+generic/684
+generic/685
+generic/686
+generic/687
+generic/688
+generic/689
+shared/002
+shared/032
+Passed all 512 tests

tests/extra/xfstests/local.exclude

@@ -0,0 +1,44 @@
+generic/003	# missing atime update in buffered read
+generic/075	# file content mismatch failures (fds, etc)
+generic/103	# enospc causes trans commit failures
+generic/108	# mount fails on failing device?
+generic/112	# file content mismatch failures (fds, etc)
+generic/213	# enospc causes trans commit failures
+generic/318	# can't support user namespaces until v5.11
+generic/321	# requires selinux enabled for '+' in ls?
+generic/338	# BUG_ON update inode error handling
+generic/347	# _dmthin_mount doesn't work?
+generic/356	# swap
+generic/357	# swap
+generic/409	# bind mounts not scripted yet
+generic/410	# bind mounts not scripted yet
+generic/411	# bind mounts not scripted yet
+generic/423	# symlink inode size is strlen() + 1 on scoutfs
+generic/430	# xfs_io copy_range missing in el7
+generic/431	# xfs_io copy_range missing in el7
+generic/432	# xfs_io copy_range missing in el7
+generic/433	# xfs_io copy_range missing in el7
+generic/434	# xfs_io copy_range missing in el7
+generic/441	# dm-mapper
+generic/444	# el9's posix_acl_update_mode is buggy ?
+generic/467	# open_by_handle ESTALE
+generic/472	# swap
+generic/484	# dm-mapper
+generic/493	# swap
+generic/494	# swap
+generic/495	# swap
+generic/496	# swap
+generic/497	# swap
+generic/532	# xfs_io statx attrib_mask missing in el7
+generic/554	# swap
+generic/563	# cgroup+loopdev
+generic/564	# xfs_io copy_range missing in el7
+generic/565	# xfs_io copy_range missing in el7
+generic/568	# falloc not resulting in block count increase
+generic/569	# swap
+generic/570	# swap
+generic/620	# dm-hugedisk
+generic/633	# id-mapped mounts missing in el7
+generic/636	# swap
+generic/641	# swap
+generic/643	# swap

tests/fenced-local-force-unmount.sh

@@ -8,36 +8,33 @@
 
 echo "$0 running rid '$SCOUTFS_FENCED_REQ_RID' ip '$SCOUTFS_FENCED_REQ_IP' args '$@'"
 
-log() {
-	echo "$@" > /dev/stderr
+echo_fail() {
+	echo "$@" >&2
 	exit 1
 }
 
-echo_fail() {
-	echo "$@" > /dev/stderr
-	exit 1
+# silence error messages
+quiet_cat()
+{
+	cat "$@" 2>/dev/null
 }
 
 rid="$SCOUTFS_FENCED_REQ_RID"
 
+shopt -s nullglob
 for fs in /sys/fs/scoutfs/*; do
-	[ ! -d "$fs" ] && continue
+	fs_rid="$(quiet_cat $fs/rid)"
+	nr="$(quiet_cat $fs/data_device_maj_min)"
+	[ ! -d "$fs" -o "$fs_rid" != "$rid" ] && continue
 
-	fs_rid="$(cat $fs/rid)" || \
-		echo_fail "failed to get rid in $fs"
-	if [ "$fs_rid" != "$rid" ]; then
-		continue
+	mnt=$(findmnt -l -n -t scoutfs -o TARGET -S $nr)
+	[ -z "$mnt" ] && continue
+
+	if ! umount -qf "$mnt"; then
+		if [ -d "$fs" ]; then
+			echo_fail "umount -qf $mnt failed"
+		fi
 	fi
-
-	nr="$(cat $fs/data_device_maj_min)" || \
-		echo_fail "failed to get data device major:minor in $fs"
-
-	mnts=$(findmnt -l -n -t scoutfs -o TARGET -S $nr) || \
-		echo_fail "findmnt -t scoutfs -S $nr failed"
-	for mnt in $mnts; do
-		umount -f "$mnt" || \
-			echo_fail "umout -f $mnt failed"
-	done
 done
 
 exit 0

tests/funcs/exec.sh

@@ -64,21 +64,27 @@ t_rc()
 }
 
 #
-# redirect test output back to the output of the invoking script intead
-# of the compared output.
+# As run, stdout/err are redirected to a file that will be compared with
+# the stored expected golden output of the test.  This redirects
+# stdout/err in the script to stdout of the invoking run-test.  It's
+# intended to give visible output of tests without being included in the
+# golden output.
 #
-t_restore_output()
+# (see the goofy "exec" fd manipulation in the main run-tests as it runs
+# each test)
+#
+t_stdout_invoked()
 {
 	exec >&6 2>&1
 }
 
 #
-# redirect a command's output back to the compared output after the
-# test has restored its output
+# This undoes t_stdout_invokved, returning the test's stdout/err to the
+# output file as it was when it was launched.
 #
-t_compare_output()
+t_stdout_compare()
 {
-	"$@" >&7 2>&1
+	exec >&7 2>&1
 }
 
 #

tests/funcs/filter.sh

@@ -121,6 +121,7 @@ t_filter_dmesg()
 
 	# in debugging kernels we can slow things down a bit
 	re="$re|hrtimer: interrupt took .*"
+	re="$re|clocksource: Long readout interval"
 
 	# fencing tests force unmounts and trigger timeouts
 	re="$re|scoutfs .* forcing unmount"
@@ -166,6 +167,12 @@ t_filter_dmesg()
 	# perf warning that it adjusted sample rate
 	re="$re|perf: interrupt took too long.*lowering kernel.perf_event_max_sample_rate.*"
 
+	# some ci test guests are unresponsive
+	re="$re|longest quorum heartbeat .* delay"
+
+	# creating block devices may trigger this
+	re="$re|block device autoloading is deprecated and will be removed."
+
 	egrep -v "($re)" | \
 		ignore_harmless_unwind_kasan_stack_oob
 }

tests/funcs/fs.sh

@@ -498,3 +498,100 @@ t_restore_all_sysfs_mount_options() {
 		t_set_sysfs_mount_option $i $name "${_saved_opts[$ind]}"
 	done
 }
+
+t_force_log_merge() {
+	local sv=$(t_server_nr)
+	local merges_started
+	local last_merges_started
+	local merges_completed
+	local last_merges_completed
+
+	while true; do
+		last_merges_started=$(t_counter log_merge_start $sv)
+		last_merges_completed=$(t_counter log_merge_complete $sv)
+
+		t_trigger_arm_silent log_merge_force_finalize_ours $sv
+
+		t_sync_seq_index
+
+		while test "$(t_trigger_get log_merge_force_finalize_ours $sv)" == "1"; do
+			sleep .5
+		done
+
+		merges_started=$(t_counter log_merge_start $sv)
+
+		if (( merges_started > last_merges_started )); then
+			merges_completed=$(t_counter log_merge_complete $sv)
+
+			while (( merges_completed == last_merges_completed )); do
+				sleep .5
+				merges_completed=$(t_counter log_merge_complete $sv)
+			done
+			break
+		fi
+	done
+}
+
+declare -A _last_scan
+t_get_orphan_scan_runs() {
+	local i
+
+	for i in $(t_fs_nrs); do
+		_last_scan[$i]=$(t_counter orphan_scan $i)
+	done
+}
+
+t_wait_for_orphan_scan_runs() {
+	local i
+	local scan
+
+	t_get_orphan_scan_runs
+
+	for i in $(t_fs_nrs); do
+		while true; do
+			scan=$(t_counter orphan_scan $i)
+			if (( scan != _last_scan[$i] )); then
+				break
+			fi
+			sleep .5
+		done
+	done
+}
+
+declare -A _last_empty
+t_get_orphan_scan_empty() {
+	local i
+
+	for i in $(t_fs_nrs); do
+		_last_empty[$i]=$(t_counter orphan_scan_empty $i)
+	done
+}
+
+t_wait_for_no_orphans() {
+	local i;
+	local working;
+	local empty;
+
+	t_get_orphan_scan_empty
+
+	while true; do
+		working=0
+
+		t_wait_for_orphan_scan_runs
+
+		for i in $(t_fs_nrs); do
+			empty=$(t_counter orphan_scan_empty $i)
+			if (( empty == _last_empty[$i] )); then
+				(( working++ ))
+			else
+				(( _last_empty[$i] = empty ))
+			fi
+		done
+
+		if (( working == 0 )); then
+			break
+		fi
+
+		sleep 1
+	done
+}

tests/funcs/tap.sh

@@ -43,9 +43,14 @@ t_tap_progress()
 	local testname=$1
 	local result=$2
 
+	local stmsg=""
 	local diff=""
 	local dmsg=""
 
+	if [[ -s $T_RESULTS/tmp/${testname}/status.msg ]]; then
+		stmsg="1"
+	fi
+
 	if [[ -s "$T_RESULTS/tmp/${testname}/dmesg.new" ]]; then
 		dmsg="1"
 	fi
@@ -61,6 +66,7 @@ t_tap_progress()
 		echo "# ${testname} ** skipped - permitted **"
 	else
 		echo "not ok ${i} - ${testname}"
+
 		case ${result} in
 		101)
 			echo "# ${testname} ** skipped **"
@@ -70,6 +76,13 @@ t_tap_progress()
 			;;
 		esac
 
+		if [[ -n "${stmsg}" ]]; then
+			echo "#"
+			echo "# status:"
+			echo "#"
+			cat $T_RESULTS/tmp/${testname}/status.msg | sed 's/^/# - /'
+		fi
+
 		if [[ -n "${diff}" ]]; then
 			echo "#"
 			echo "# diff:"

tests/golden/inode-deletion

@@ -17,7 +17,7 @@ ino not found in dseq index
 mount 0 contents after mount 1 rm: contents
 ino found in dseq index
 ino found in dseq index
-stat: cannot stat '/mnt/test/test/inode-deletion/file': No such file or directory
+stat: cannot stat '/mnt/test/test/inode-deletion/badfile': No such file or directory
 ino not found in dseq index
 ino not found in dseq index
 == lots of deletions use one open map

tests/golden/srch-safe-merge-pos

@@ -1,37 +1,7 @@
 == initialize per-mount values
 == arm compaction triggers
-trigger srch_compact_logs_pad_safe armed: 1
-trigger srch_merge_stop_safe armed: 1
-trigger srch_compact_logs_pad_safe armed: 1
-trigger srch_merge_stop_safe armed: 1
-trigger srch_compact_logs_pad_safe armed: 1
-trigger srch_merge_stop_safe armed: 1
-trigger srch_compact_logs_pad_safe armed: 1
-trigger srch_merge_stop_safe armed: 1
-trigger srch_compact_logs_pad_safe armed: 1
-trigger srch_merge_stop_safe armed: 1
 == compact more often
 == create padded sorted inputs by forcing log rotation
-trigger srch_force_log_rotate armed: 1
-trigger srch_force_log_rotate armed: 1
-trigger srch_force_log_rotate armed: 1
-trigger srch_force_log_rotate armed: 1
-trigger srch_compact_logs_pad_safe armed: 1
-trigger srch_force_log_rotate armed: 1
-trigger srch_force_log_rotate armed: 1
-trigger srch_force_log_rotate armed: 1
-trigger srch_force_log_rotate armed: 1
-trigger srch_compact_logs_pad_safe armed: 1
-trigger srch_force_log_rotate armed: 1
-trigger srch_force_log_rotate armed: 1
-trigger srch_force_log_rotate armed: 1
-trigger srch_force_log_rotate armed: 1
-trigger srch_compact_logs_pad_safe armed: 1
-trigger srch_force_log_rotate armed: 1
-trigger srch_force_log_rotate armed: 1
-trigger srch_force_log_rotate armed: 1
-trigger srch_force_log_rotate armed: 1
-trigger srch_compact_logs_pad_safe armed: 1
 == compaction of padded should stop at safe
 == verify no compaction errors
 == cleanup

tests/golden/xfstests

@@ -1,882 +0,0 @@
-Ran:
-generic/001
-generic/002
-generic/004
-generic/005
-generic/006
-generic/007
-generic/008
-generic/009
-generic/011
-generic/012
-generic/013
-generic/014
-generic/015
-generic/016
-generic/018
-generic/020
-generic/021
-generic/022
-generic/023
-generic/024
-generic/025
-generic/026
-generic/028
-generic/029
-generic/030
-generic/031
-generic/032
-generic/033
-generic/034
-generic/035
-generic/037
-generic/039
-generic/040
-generic/041
-generic/050
-generic/052
-generic/053
-generic/056
-generic/057
-generic/058
-generic/059
-generic/060
-generic/061
-generic/062
-generic/063
-generic/064
-generic/065
-generic/066
-generic/067
-generic/069
-generic/070
-generic/071
-generic/073
-generic/076
-generic/078
-generic/079
-generic/080
-generic/081
-generic/082
-generic/084
-generic/086
-generic/087
-generic/088
-generic/090
-generic/091
-generic/092
-generic/094
-generic/096
-generic/097
-generic/098
-generic/099
-generic/101
-generic/104
-generic/105
-generic/106
-generic/107
-generic/110
-generic/111
-generic/113
-generic/114
-generic/115
-generic/116
-generic/117
-generic/118
-generic/119
-generic/120
-generic/121
-generic/122
-generic/123
-generic/124
-generic/126
-generic/128
-generic/129
-generic/130
-generic/131
-generic/134
-generic/135
-generic/136
-generic/138
-generic/139
-generic/140
-generic/141
-generic/142
-generic/143
-generic/144
-generic/145
-generic/146
-generic/147
-generic/148
-generic/149
-generic/150
-generic/151
-generic/152
-generic/153
-generic/154
-generic/155
-generic/156
-generic/157
-generic/158
-generic/159
-generic/160
-generic/161
-generic/162
-generic/163
-generic/169
-generic/171
-generic/172
-generic/173
-generic/174
-generic/177
-generic/178
-generic/179
-generic/180
-generic/181
-generic/182
-generic/183
-generic/184
-generic/185
-generic/188
-generic/189
-generic/190
-generic/191
-generic/193
-generic/194
-generic/195
-generic/196
-generic/197
-generic/198
-generic/199
-generic/200
-generic/201
-generic/202
-generic/203
-generic/205
-generic/206
-generic/207
-generic/210
-generic/211
-generic/212
-generic/214
-generic/215
-generic/216
-generic/217
-generic/218
-generic/219
-generic/220
-generic/221
-generic/222
-generic/223
-generic/225
-generic/227
-generic/228
-generic/229
-generic/230
-generic/235
-generic/236
-generic/237
-generic/238
-generic/240
-generic/244
-generic/245
-generic/246
-generic/247
-generic/248
-generic/249
-generic/250
-generic/252
-generic/253
-generic/254
-generic/255
-generic/256
-generic/257
-generic/258
-generic/259
-generic/260
-generic/261
-generic/262
-generic/263
-generic/264
-generic/265
-generic/266
-generic/267
-generic/268
-generic/271
-generic/272
-generic/276
-generic/277
-generic/278
-generic/279
-generic/281
-generic/282
-generic/283
-generic/284
-generic/286
-generic/287
-generic/288
-generic/289
-generic/290
-generic/291
-generic/292
-generic/293
-generic/294
-generic/295
-generic/296
-generic/301
-generic/302
-generic/303
-generic/304
-generic/305
-generic/306
-generic/307
-generic/308
-generic/309
-generic/312
-generic/313
-generic/314
-generic/315
-generic/316
-generic/317
-generic/319
-generic/322
-generic/324
-generic/325
-generic/326
-generic/327
-generic/328
-generic/329
-generic/330
-generic/331
-generic/332
-generic/335
-generic/336
-generic/337
-generic/341
-generic/342
-generic/343
-generic/346
-generic/348
-generic/353
-generic/355
-generic/358
-generic/359
-generic/360
-generic/361
-generic/362
-generic/363
-generic/364
-generic/365
-generic/366
-generic/367
-generic/368
-generic/369
-generic/370
-generic/371
-generic/372
-generic/373
-generic/374
-generic/375
-generic/376
-generic/377
-generic/378
-generic/379
-generic/380
-generic/381
-generic/382
-generic/383
-generic/384
-generic/385
-generic/386
-generic/389
-generic/391
-generic/392
-generic/393
-generic/394
-generic/395
-generic/396
-generic/397
-generic/398
-generic/400
-generic/401
-generic/402
-generic/403
-generic/404
-generic/406
-generic/407
-generic/408
-generic/412
-generic/413
-generic/414
-generic/417
-generic/419
-generic/420
-generic/421
-generic/422
-generic/424
-generic/425
-generic/426
-generic/427
-generic/428
-generic/436
-generic/437
-generic/439
-generic/440
-generic/443
-generic/445
-generic/446
-generic/448
-generic/449
-generic/450
-generic/451
-generic/452
-generic/453
-generic/454
-generic/456
-generic/458
-generic/460
-generic/462
-generic/463
-generic/465
-generic/466
-generic/468
-generic/469
-generic/470
-generic/471
-generic/474
-generic/477
-generic/478
-generic/479
-generic/480
-generic/481
-generic/483
-generic/485
-generic/486
-generic/487
-generic/488
-generic/489
-generic/490
-generic/491
-generic/492
-generic/498
-generic/499
-generic/501
-generic/502
-generic/503
-generic/504
-generic/505
-generic/506
-generic/507
-generic/508
-generic/509
-generic/510
-generic/511
-generic/512
-generic/513
-generic/514
-generic/515
-generic/516
-generic/517
-generic/518
-generic/519
-generic/520
-generic/523
-generic/524
-generic/525
-generic/526
-generic/527
-generic/528
-generic/529
-generic/530
-generic/531
-generic/533
-generic/534
-generic/535
-generic/536
-generic/537
-generic/538
-generic/539
-generic/540
-generic/541
-generic/542
-generic/543
-generic/544
-generic/545
-generic/546
-generic/547
-generic/548
-generic/549
-generic/550
-generic/552
-generic/553
-generic/555
-generic/556
-generic/557
-generic/566
-generic/567
-generic/571
-generic/572
-generic/573
-generic/574
-generic/575
-generic/576
-generic/577
-generic/578
-generic/580
-generic/581
-generic/582
-generic/583
-generic/584
-generic/586
-generic/587
-generic/588
-generic/591
-generic/592
-generic/593
-generic/594
-generic/595
-generic/596
-generic/597
-generic/598
-generic/599
-generic/600
-generic/601
-generic/602
-generic/603
-generic/604
-generic/605
-generic/606
-generic/607
-generic/608
-generic/609
-generic/610
-generic/611
-generic/612
-generic/613
-generic/614
-generic/618
-generic/621
-generic/623
-generic/624
-generic/625
-generic/626
-generic/628
-generic/629
-generic/630
-generic/632
-generic/634
-generic/635
-generic/637
-generic/638
-generic/639
-generic/640
-generic/644
-generic/645
-generic/646
-generic/647
-generic/651
-generic/652
-generic/653
-generic/654
-generic/655
-generic/657
-generic/658
-generic/659
-generic/660
-generic/661
-generic/662
-generic/663
-generic/664
-generic/665
-generic/666
-generic/667
-generic/668
-generic/669
-generic/673
-generic/674
-generic/675
-generic/676
-generic/677
-generic/678
-generic/679
-generic/680
-generic/681
-generic/682
-generic/683
-generic/684
-generic/685
-generic/686
-generic/687
-generic/688
-generic/689
-shared/002
-shared/032
-Not
-run:
-generic/008
-generic/009
-generic/012
-generic/015
-generic/016
-generic/018
-generic/021
-generic/022
-generic/025
-generic/026
-generic/031
-generic/033
-generic/050
-generic/052
-generic/058
-generic/059
-generic/060
-generic/061
-generic/063
-generic/064
-generic/078
-generic/079
-generic/081
-generic/082
-generic/091
-generic/094
-generic/096
-generic/110
-generic/111
-generic/113
-generic/114
-generic/115
-generic/116
-generic/118
-generic/119
-generic/121
-generic/122
-generic/123
-generic/128
-generic/130
-generic/134
-generic/135
-generic/136
-generic/138
-generic/139
-generic/140
-generic/142
-generic/143
-generic/144
-generic/145
-generic/146
-generic/147
-generic/148
-generic/149
-generic/150
-generic/151
-generic/152
-generic/153
-generic/154
-generic/155
-generic/156
-generic/157
-generic/158
-generic/159
-generic/160
-generic/161
-generic/162
-generic/163
-generic/171
-generic/172
-generic/173
-generic/174
-generic/177
-generic/178
-generic/179
-generic/180
-generic/181
-generic/182
-generic/183
-generic/185
-generic/188
-generic/189
-generic/190
-generic/191
-generic/193
-generic/194
-generic/195
-generic/196
-generic/197
-generic/198
-generic/199
-generic/200
-generic/201
-generic/202
-generic/203
-generic/205
-generic/206
-generic/207
-generic/210
-generic/211
-generic/212
-generic/214
-generic/216
-generic/217
-generic/218
-generic/219
-generic/220
-generic/222
-generic/223
-generic/225
-generic/227
-generic/229
-generic/230
-generic/235
-generic/238
-generic/240
-generic/244
-generic/250
-generic/252
-generic/253
-generic/254
-generic/255
-generic/256
-generic/259
-generic/260
-generic/261
-generic/262
-generic/263
-generic/264
-generic/265
-generic/266
-generic/267
-generic/268
-generic/271
-generic/272
-generic/276
-generic/277
-generic/278
-generic/279
-generic/281
-generic/282
-generic/283
-generic/284
-generic/287
-generic/288
-generic/289
-generic/290
-generic/291
-generic/292
-generic/293
-generic/295
-generic/296
-generic/301
-generic/302
-generic/303
-generic/304
-generic/305
-generic/312
-generic/314
-generic/316
-generic/317
-generic/324
-generic/326
-generic/327
-generic/328
-generic/329
-generic/330
-generic/331
-generic/332
-generic/353
-generic/355
-generic/358
-generic/359
-generic/361
-generic/362
-generic/363
-generic/364
-generic/365
-generic/366
-generic/367
-generic/368
-generic/369
-generic/370
-generic/371
-generic/372
-generic/373
-generic/374
-generic/378
-generic/379
-generic/380
-generic/381
-generic/382
-generic/383
-generic/384
-generic/385
-generic/386
-generic/391
-generic/392
-generic/395
-generic/396
-generic/397
-generic/398
-generic/400
-generic/402
-generic/404
-generic/406
-generic/407
-generic/408
-generic/412
-generic/413
-generic/414
-generic/417
-generic/419
-generic/420
-generic/421
-generic/422
-generic/424
-generic/425
-generic/427
-generic/439
-generic/440
-generic/446
-generic/449
-generic/450
-generic/451
-generic/453
-generic/454
-generic/456
-generic/458
-generic/462
-generic/463
-generic/465
-generic/466
-generic/468
-generic/469
-generic/470
-generic/471
-generic/474
-generic/485
-generic/487
-generic/488
-generic/491
-generic/492
-generic/499
-generic/501
-generic/503
-generic/505
-generic/506
-generic/507
-generic/508
-generic/511
-generic/513
-generic/514
-generic/515
-generic/516
-generic/517
-generic/518
-generic/519
-generic/520
-generic/528
-generic/530
-generic/536
-generic/537
-generic/538
-generic/539
-generic/540
-generic/541
-generic/542
-generic/543
-generic/544
-generic/545
-generic/546
-generic/548
-generic/549
-generic/550
-generic/552
-generic/553
-generic/555
-generic/556
-generic/566
-generic/567
-generic/572
-generic/573
-generic/574
-generic/575
-generic/576
-generic/577
-generic/578
-generic/580
-generic/581
-generic/582
-generic/583
-generic/584
-generic/586
-generic/587
-generic/588
-generic/591
-generic/592
-generic/593
-generic/594
-generic/595
-generic/596
-generic/597
-generic/598
-generic/599
-generic/600
-generic/601
-generic/602
-generic/603
-generic/605
-generic/606
-generic/607
-generic/608
-generic/609
-generic/610
-generic/612
-generic/613
-generic/621
-generic/623
-generic/624
-generic/625
-generic/626
-generic/628
-generic/629
-generic/630
-generic/635
-generic/644
-generic/645
-generic/646
-generic/647
-generic/651
-generic/652
-generic/653
-generic/654
-generic/655
-generic/657
-generic/658
-generic/659
-generic/660
-generic/661
-generic/662
-generic/663
-generic/664
-generic/665
-generic/666
-generic/667
-generic/668
-generic/669
-generic/673
-generic/674
-generic/675
-generic/677
-generic/678
-generic/679
-generic/680
-generic/681
-generic/682
-generic/683
-generic/684
-generic/685
-generic/686
-generic/687
-generic/688
-generic/689
-shared/002
-shared/032
-Passed all 512 tests

tests/run-tests.sh

@@ -137,6 +137,9 @@ while true; do
 	        test -n "$2" || die "-l must have a nr iterations argument"
 		test "$2" -eq "$2" 2>/dev/null || die "-l <nr> argument must be an integer"
 		T_LOOP_ITER="$2"
+
+		# when looping, break after first failure
+		T_ABORT="1"
 		shift
 		;;
 	-M)
@@ -399,30 +402,44 @@ if [ -n "$T_INSMOD" ]; then
 	cmd insmod "$T_MODULE"
 fi
 
-if [ -n "$T_TRACE_MULT" ]; then
-	orig_trace_size=$(cat /sys/kernel/debug/tracing/buffer_size_kb)
-	mult_trace_size=$((orig_trace_size * T_TRACE_MULT))
-	msg "increasing trace buffer size from $orig_trace_size KiB to $mult_trace_size KiB"
-	echo $mult_trace_size > /sys/kernel/debug/tracing/buffer_size_kb
-fi
+start_tracing() {
+	if [ -n "$T_TRACE_MULT" ]; then
+		orig_trace_size=1408
+		mult_trace_size=$((orig_trace_size * T_TRACE_MULT))
+		msg "increasing trace buffer size from $orig_trace_size KiB to $mult_trace_size KiB"
+		echo $mult_trace_size > /sys/kernel/debug/tracing/buffer_size_kb
+	fi
 
-nr_globs=${#T_TRACE_GLOB[@]}
-if [ $nr_globs -gt 0 ]; then
-	echo 0 > /sys/kernel/debug/tracing/events/scoutfs/enable
+	nr_globs=${#T_TRACE_GLOB[@]}
+	if [ $nr_globs -gt 0 ]; then
+		echo 0 > /sys/kernel/debug/tracing/events/scoutfs/enable
 
-	for g in "${T_TRACE_GLOB[@]}"; do
-		for e in /sys/kernel/debug/tracing/events/scoutfs/$g/enable; do
-			if test -w "$e"; then
-				echo 1 > "$e"
-			else
-				die "-t glob '$g' matched no scoutfs events"
-			fi
+		for g in "${T_TRACE_GLOB[@]}"; do
+			for e in /sys/kernel/debug/tracing/events/scoutfs/$g/enable; do
+				if test -w "$e"; then
+					echo 1 > "$e"
+				else
+					die "-t glob '$g' matched no scoutfs events"
+				fi
+			done
 		done
-	done
 
-	nr_events=$(cat /sys/kernel/debug/tracing/set_event | wc -l)
-	msg "enabled $nr_events trace events from $nr_globs -t globs"
-fi
+		nr_events=$(cat /sys/kernel/debug/tracing/set_event | wc -l)
+		msg "enabled $nr_events trace events from $nr_globs -t globs"
+	fi
+}
+
+stop_tracing() {
+	if [ -n "$T_TRACE_GLOB" -o -n "$T_TRACE_PRINTK" ]; then
+		msg "saving traces and disabling tracing"
+		echo 0 > /sys/kernel/debug/tracing/events/scoutfs/enable
+		echo 0 > /sys/kernel/debug/tracing/options/trace_printk
+		cat /sys/kernel/debug/tracing/trace | gzip > "$T_RESULTS/traces.gz"
+		if [ -n "$orig_trace_size" ]; then
+			echo $orig_trace_size > /sys/kernel/debug/tracing/buffer_size_kb
+		fi
+	fi
+}
 
 if [ -n "$T_TRACE_PRINTK" ]; then
 	echo "$T_TRACE_PRINTK" > /sys/kernel/debug/tracing/options/trace_printk
@@ -438,6 +455,30 @@ cmd grep .  /sys/kernel/debug/tracing/options/trace_printk \
 	    /sys/kernel/debug/tracing/buffer_size_kb \
 	    /proc/sys/kernel/ftrace_dump_on_oops
 
+# we can record pids to kill as we exit, we kill in reverse added order
+atexit_kill_pids=""
+add_atexit_kill_pid()
+{
+	atexit_kill_pids="$1 $atexit_kill_pids"
+}
+atexit_kill()
+{
+	local pid
+
+	# suppress bg function exited messages
+	exec {ERR}>&2 2>/dev/null
+
+	for pid in $atexit_kill_pids; do
+		if test -e "/proc/$pid/status" ; then
+			kill "$pid"
+			wait "$pid"
+		fi
+	done
+
+	exec 2>&$ERR {ERR}>&-
+}
+trap atexit_kill EXIT
+
 #
 # Build a fenced config that runs scripts out of the repository rather
 # than the default system directory
@@ -451,26 +492,43 @@ EOF
 export SCOUTFS_FENCED_CONFIG_FILE="$conf"
 T_FENCED_LOG="$T_RESULTS/fenced.log"
 
-#
-# Run the agent in the background, log its output, an kill it if we
-# exit
-#
-fenced_log()
-{
-	echo "[$(timestamp)] $*" >> "$T_FENCED_LOG"
-}
-fenced_pid=""
-kill_fenced()
-{
-	if test -n "$fenced_pid" -a -d "/proc/$fenced_pid" ; then
-		fenced_log "killing fenced pid $fenced_pid"
-		kill "$fenced_pid"
-	fi
-}
-trap kill_fenced EXIT
 $T_UTILS/fenced/scoutfs-fenced > "$T_FENCED_LOG" 2>&1 &
 fenced_pid=$!
-fenced_log "started fenced pid $fenced_pid in the background"
+add_atexit_kill_pid $fenced_pid
+
+#
+# some critical failures will cause fs operations to hang.  We can watch
+# for evidence of them and cause the system to crash, at least.
+#
+crash_monitor()
+{
+	local bad=0
+
+	while sleep 1; do
+		if dmesg | grep -q "inserting extent.*overlaps existing"; then
+			echo "run-tests monitor saw overlapping extent message"
+			bad=1
+		fi
+
+		if dmesg | grep -q "error indicated by fence action" ; then
+			echo "run-tests monitor saw fence agent error message"
+			bad=1
+		fi
+
+		if [ ! -e "/proc/${fenced_pid}/status" ]; then
+			echo "run-tests monitor didn't see fenced pid $fenced_pid /proc dir"
+			bad=1
+		fi
+
+		if [ "$bad" != 0 ]; then
+			echo "run-tests monitor triggering crash"
+			echo c > /proc/sysrq-trigger
+			exit 1
+		fi
+	done
+}
+crash_monitor &
+add_atexit_kill_pid $!
 
 # setup dm tables
 echo "0 $(blockdev --getsz $T_META_DEVICE) linear $T_META_DEVICE 0" > \
@@ -558,21 +616,26 @@ passed=0
 skipped=0
 failed=0
 skipped_permitted=0
-for t in $tests; do
-	# tests has basenames from sequence, get path and name
-	t="tests/$t"
-	test_name=$(basename "$t" | sed -e 's/.sh$//')
+for iter in $(seq 1 $T_LOOP_ITER); do
 
-	# get stats from previous pass
-	last="$T_RESULTS/last-passed-test-stats"
-	stats=$(grep -s "^$test_name " "$last" | cut -d " " -f 2-)
-	test -n "$stats" && stats="last: $stats"
-	printf "  %-30s $stats" "$test_name"
+	start_tracing
 
-	# mark in dmesg as to what test we are running
-	echo "run scoutfs test $test_name" > /dev/kmsg
+	for t in $tests; do
+		# tests has basenames from sequence, get path and name
+		t="tests/$t"
+		test_name=$(basename "$t" | sed -e 's/.sh$//')
 
-	for iter in $(seq 1 $T_LOOP_ITER); do
+		# get stats from previous pass
+		last="$T_RESULTS/last-passed-test-stats"
+		stats=$(grep -s "^$test_name " "$last" | cut -d " " -f 2-)
+		test -n "$stats" && stats="last: $stats"
+		printf "  %-30s $stats" "$test_name"
+
+		# mark in dmesg as to what test we are running
+		echo "run scoutfs test $test_name" > /dev/kmsg
+
+		# let the test get at its extra files
+		T_EXTRA="$T_TESTS/extra/$test_name"
 
 		# create a temporary dir and file path for the test
 		T_TMPDIR="$T_RESULTS/tmp/$test_name"
@@ -659,55 +722,43 @@ for t in $tests; do
 			sts=$T_FAIL_STATUS
 		fi
 
-		# stop looping if we didn't pass
-		if [ "$sts" != "$T_PASS_STATUS" ]; then
-			break;
+		# show and record the result of the test
+		if [ "$sts" == "$T_PASS_STATUS" ]; then
+			echo "  passed: $stats"
+			((passed++))
+			# save stats for passed test
+			grep -s -v "^$test_name " "$last" > "$last.tmp"
+			echo "$test_name $stats" >> "$last.tmp"
+			mv -f "$last.tmp" "$last"
+		elif [ "$sts" == "$T_SKIP_PERMITTED_STATUS" ]; then
+			echo "  [ skipped (permitted): $message ]"
+			echo "$test_name skipped (permitted) $message " >> "$T_RESULTS/skip.log"
+			((skipped_permitted++))
+		elif [ "$sts" == "$T_SKIP_STATUS" ]; then
+			echo "  [ skipped: $message ]"
+			echo "$test_name $message" >> "$T_RESULTS/skip.log"
+			((skipped++))
+		elif [ "$sts" == "$T_FAIL_STATUS" ]; then
+			echo "  [ failed: $message ]"
+			echo "$test_name $message" >> "$T_RESULTS/fail.log"
+			((failed++))
+
+			if [ -n "$T_ABORT" ]; then
+				stop_tracing
+				die "aborting after first failure"
+			fi
 		fi
+
+		# record results for TAP format output
+		t_tap_progress $test_name $sts
+		((testcount++))
 	done
 
-	# show and record the result of the test
-	if [ "$sts" == "$T_PASS_STATUS" ]; then
-		echo "  passed: $stats"
-		((passed++))
-		# save stats for passed test
-		grep -s -v "^$test_name " "$last" > "$last.tmp"
-		echo "$test_name $stats" >> "$last.tmp"
-		mv -f "$last.tmp" "$last"
-	elif [ "$sts" == "$T_SKIP_PERMITTED_STATUS" ]; then
-		echo "  [ skipped (permitted): $message ]"
-		echo "$test_name skipped (permitted) $message " >> "$T_RESULTS/skip.log"
-		((skipped_permitted++))
-	elif [ "$sts" == "$T_SKIP_STATUS" ]; then
-		echo "  [ skipped: $message ]"
-		echo "$test_name $message" >> "$T_RESULTS/skip.log"
-		((skipped++))
-	elif [ "$sts" == "$T_FAIL_STATUS" ]; then
-		echo "  [ failed: $message ]"
-		echo "$test_name $message" >> "$T_RESULTS/fail.log"
-		((failed++))
-
-		test -n "$T_ABORT" && die "aborting after first failure"
-	fi
-
-	# record results for TAP format output
-	t_tap_progress $test_name $sts
-	((testcount++))
-
+	stop_tracing
 done
 
 msg "all tests run: $passed passed, $skipped skipped, $skipped_permitted skipped (permitted), $failed failed"
 
-
-if [ -n "$T_TRACE_GLOB" -o -n "$T_TRACE_PRINTK" ]; then
-	msg "saving traces and disabling tracing"
-	echo 0 > /sys/kernel/debug/tracing/events/scoutfs/enable
-	echo 0 > /sys/kernel/debug/tracing/options/trace_printk
-	cat /sys/kernel/debug/tracing/trace > "$T_RESULTS/traces"
-	if [ -n "$orig_trace_size" ]; then
-		echo $orig_trace_size > /sys/kernel/debug/tracing/buffer_size_kb
-	fi
-fi
-
 if [ "$skipped" == 0 -a "$failed" == 0 ]; then
 	msg "all tests passed"
 	unmount_all

tests/src/mmap_stress.c

@@ -19,6 +19,7 @@
 #include <sys/types.h>
 #include <stdio.h>
 #include <sys/stat.h>
+#include <inttypes.h>
 #include <fcntl.h>
 #include <unistd.h>
 #include <stdlib.h>
@@ -29,7 +30,7 @@
 #include <errno.h>
 
 static int size = 0;
-static int count = 0; /* XXX make this duration instead */
+static int duration = 0;
 
 struct thread_info {
 	int nr;
@@ -41,6 +42,8 @@ static void *run_test_func(void *ptr)
 	void *buf = NULL;
 	char *addr = NULL;
 	struct thread_info *tinfo = ptr;
+	uint64_t seconds = 0;
+	struct timespec ts;
 	int c = 0;
 	int fd;
 	ssize_t read, written, ret;
@@ -61,9 +64,15 @@ static void *run_test_func(void *ptr)
 
 	usleep(100000); /* 0.1sec to allow all threads to start roughly at the same time */
 
+	clock_gettime(CLOCK_REALTIME, &ts); /* record start time */
+	seconds = ts.tv_sec + duration;
+
 	for (;;) {
-		if (++c > count)
-			break;
+		if (++c % 16 == 0) {
+			clock_gettime(CLOCK_REALTIME, &ts);
+			if (ts.tv_sec >= seconds)
+				break;
+		}
 
 		switch (rand() % 4) {
 		case 0: /* pread */
@@ -99,6 +108,8 @@ static void *run_test_func(void *ptr)
 			memcpy(addr, buf, size); /* noerr */
 			break;
 		}
+
+		usleep(10000);
 	}
 
 	munmap(addr, size);
@@ -120,7 +131,7 @@ int main(int argc, char **argv)
 	int i;
 
 	if (argc != 8) {
-		fprintf(stderr, "%s requires 7 arguments - size count file1 file2 file3 file4 file5\n", argv[0]);
+		fprintf(stderr, "%s requires 7 arguments - size duration file1 file2 file3 file4 file5\n", argv[0]);
 		exit(-1);
 	}
 
@@ -130,9 +141,9 @@ int main(int argc, char **argv)
 		exit(-1);
 	}
 
-	count = atoi(argv[2]);
-	if (count < 0) {
-		fprintf(stderr, "invalid count, must be greater than 0\n");
+	duration = atoi(argv[2]);
+	if (duration < 0) {
+		fprintf(stderr, "invalid duration, must be greater than or equal to 0\n");
 		exit(-1);
 	}
 

tests/tests/get-referring-entries.sh

@@ -72,7 +72,7 @@ touch $T_D0/dir/file
 mkdir $T_D0/dir/dir
 ln -s $T_D0/dir/file $T_D0/dir/symlink
 mknod $T_D0/dir/char c 1 3 # null
-mknod $T_D0/dir/block b 7 0 # loop0
+mknod $T_D0/dir/block b 42 0 # SAMPLE block dev - nonexistant/demo use only number
 for name in $(ls -UA $T_D0/dir | sort); do
 	ino=$(stat -c '%i' $T_D0/dir/$name)
 	$GRE $ino | filter_types

tests/tests/inode-deletion.sh

@@ -61,18 +61,28 @@ rm -f "$T_D1/file"
 check_ino_index "$ino" "$dseq" "$T_M0"
 check_ino_index "$ino" "$dseq" "$T_M1"
 
+# Hurry along the orphan scanners. If any are currently asleep, we will
+# have to wait at least their current scan interval before they wake up,
+# run, and notice their new interval.
+t_save_all_sysfs_mount_options orphan_scan_delay_ms
+t_set_all_sysfs_mount_options orphan_scan_delay_ms 500
+t_wait_for_orphan_scan_runs
+
 echo "== unlink wait for open on other mount"
-echo "contents" > "$T_D0/file"
-ino=$(stat -c "%i" "$T_D0/file")
-dseq=$(scoutfs stat -s data_seq "$T_D0/file")
-exec {FD}<"$T_D0/file"
-rm -f "$T_D1/file"
+echo "contents" > "$T_D0/badfile"
+ino=$(stat -c "%i" "$T_D0/badfile")
+dseq=$(scoutfs stat -s data_seq "$T_D0/badfile")
+exec {FD}<"$T_D0/badfile"
+rm -f "$T_D1/badfile"
 echo "mount 0 contents after mount 1 rm: $(cat <&$FD)"
 check_ino_index "$ino" "$dseq" "$T_M0"
 check_ino_index "$ino" "$dseq" "$T_M1"
 exec {FD}>&-  # close
 # we know that revalidating will unhash the remote dentry
-stat "$T_D0/file" 2>&1 | sed 's/cannot statx/cannot stat/' | t_filter_fs
+stat "$T_D0/badfile" 2>&1 | sed 's/cannot statx/cannot stat/' | t_filter_fs
+t_force_log_merge
+# wait for orphan scanners to pick up the unlinked inode and become idle
+t_wait_for_no_orphans
 check_ino_index "$ino" "$dseq" "$T_M0"
 check_ino_index "$ino" "$dseq" "$T_M1"
 
@@ -83,16 +93,20 @@ rm -f "$T_D0/dir"/files-*
 rmdir "$T_D0/dir"
 
 echo "== open files survive remote scanning orphans"
-echo "contents" > "$T_D0/file"
-ino=$(stat -c "%i" "$T_D0/file")
-dseq=$(scoutfs stat -s data_seq "$T_D0/file")
-exec {FD}<"$T_D0/file"
-rm -f "$T_D0/file"
+echo "contents" > "$T_D0/lastfile"
+ino=$(stat -c "%i" "$T_D0/lastfile")
+dseq=$(scoutfs stat -s data_seq "$T_D0/lastfile")
+exec {FD}<"$T_D0/lastfile"
+rm -f "$T_D0/lastfile"
 t_umount 1
 t_mount 1
 echo "mount 0 contents after mount 1 remounted: $(cat <&$FD)"
 exec {FD}>&-  # close
+t_force_log_merge
+t_wait_for_no_orphans
 check_ino_index "$ino" "$dseq" "$T_M0"
 check_ino_index "$ino" "$dseq" "$T_M1"
 
+t_restore_all_sysfs_mount_options orphan_scan_delay_ms
+
 t_pass

tests/tests/mmap.sh

@@ -5,7 +5,7 @@
 t_require_commands mmap_stress mmap_validate scoutfs xfs_io
 
 echo "== mmap_stress"
-mmap_stress 8192 2000 "$T_D0/mmap_stress" "$T_D1/mmap_stress" "$T_D2/mmap_stress" "$T_D3/mmap_stress" "$T_D4/mmap_stress" | sed 's/:.*//g' | sort
+mmap_stress 8192 30 "$T_D0/mmap_stress" "$T_D0/mmap_stress" "$T_D0/mmap_stress" "$T_D3/mmap_stress" "$T_D3/mmap_stress" | sed 's/:.*//g' | sort
 
 echo "== basic mmap/read/write consistency checks"
 mmap_validate 256 1000 "$T_D0/mmap_val1" "$T_D1/mmap_val1"

tests/tests/renameat2-noreplace.sh

@@ -8,19 +8,19 @@ t_require_mounts 2
 echo "=== renameat2 noreplace flag test"
 
 # give each mount their own dir (lock group) to minimize create contention
-mkdir $T_M0/dir0
-mkdir $T_M1/dir1
+mkdir $T_D0/dir0
+mkdir $T_D1/dir1
 
 echo "=== run two asynchronous calls to renameat2 NOREPLACE"
 for i in $(seq 0 100); do
         # prepare inputs in isolation
-        touch "$T_M0/dir0/old0"
-        touch "$T_M1/dir1/old1"
+        touch "$T_D0/dir0/old0"
+        touch "$T_D1/dir1/old1"
 
         # race doing noreplace renames, both can't succeed
-        dumb_renameat2 -n "$T_M0/dir0/old0" "$T_M0/dir0/sharednew" 2> /dev/null &
+        dumb_renameat2 -n "$T_D0/dir0/old0" "$T_D0/dir0/sharednew" 2> /dev/null &
         pid0=$!
-        dumb_renameat2 -n "$T_M1/dir1/old1" "$T_M1/dir0/sharednew" 2> /dev/null &
+        dumb_renameat2 -n "$T_D1/dir1/old1" "$T_D1/dir0/sharednew" 2> /dev/null &
         pid1=$!
 
         wait $pid0
@@ -31,7 +31,7 @@ for i in $(seq 0 100); do
         test "$rc0" == 0 -a "$rc1" == 0 && t_fail "both renames succeeded"
 
         # blow away possible files for either race outcome
-        rm -f "$T_M0/dir0/old0" "$T_M1/dir1/old1" "$T_M0/dir0/sharednew" "$T_M1/dir1/sharednew"
+        rm -f "$T_D0/dir0/old0" "$T_D1/dir1/old1" "$T_D0/dir0/sharednew" "$T_D1/dir1/sharednew"
 done
 
 t_pass

tests/tests/srch-safe-merge-pos.sh

@@ -31,8 +31,8 @@ trap restore_compact_delay EXIT
 
 echo "== arm compaction triggers"
 for nr in $(t_fs_nrs); do
-	t_trigger_arm srch_compact_logs_pad_safe $nr
-	t_trigger_arm srch_merge_stop_safe $nr
+	t_trigger_arm_silent srch_compact_logs_pad_safe $nr
+	t_trigger_arm_silent srch_merge_stop_safe $nr
 done
 
 echo "== compact more often"
@@ -44,7 +44,7 @@ echo "== create padded sorted inputs by forcing log rotation"
 sv=$(t_server_nr)
 for i in $(seq 1 $COMPACT_NR); do
 	for j in $(seq 1 $COMPACT_NR); do
-		t_trigger_arm srch_force_log_rotate $sv
+		t_trigger_arm_silent srch_force_log_rotate $sv
 
 		seq -f "f-$i-$j-$SEQF" 1 10 | \
 			bulk_create_paths -X "scoutfs.srch.t-srch-safe-merge-pos" -d "$T_D0" > \
@@ -59,7 +59,7 @@ for i in $(seq 1 $COMPACT_NR); do
 	while test $padded == 0 && sleep .5; do
 		for nr in $(t_fs_nrs); do
 			if [ "$(t_trigger_get srch_compact_logs_pad_safe $nr)" == "0" ]; then
-				t_trigger_arm srch_compact_logs_pad_safe $nr
+				t_trigger_arm_silent srch_compact_logs_pad_safe $nr
 				padded=1
 				break
 			fi

tests/tests/xfstests.sh

@@ -63,73 +63,47 @@ export MOUNT_OPTIONS="-o quorum_slot_nr=0,metadev_path=$T_MB0"
 export TEST_FS_MOUNT_OPTS="-o quorum_slot_nr=0,metadev_path=$T_MB0"
 EOF
 
-cat << EOF > local.exclude
-generic/003	# missing atime update in buffered read
-generic/075	# file content mismatch failures (fds, etc)
-generic/103	# enospc causes trans commit failures
-generic/108	# mount fails on failing device?
-generic/112	# file content mismatch failures (fds, etc)
-generic/213	# enospc causes trans commit failures
-generic/318	# can't support user namespaces until v5.11
-generic/321	# requires selinux enabled for '+' in ls?
-generic/338	# BUG_ON update inode error handling
-generic/347	# _dmthin_mount doesn't work?
-generic/356	# swap
-generic/357	# swap
-generic/409	# bind mounts not scripted yet
-generic/410	# bind mounts not scripted yet
-generic/411	# bind mounts not scripted yet
-generic/423	# symlink inode size is strlen() + 1 on scoutfs
-generic/430	# xfs_io copy_range missing in el7
-generic/431	# xfs_io copy_range missing in el7
-generic/432	# xfs_io copy_range missing in el7
-generic/433	# xfs_io copy_range missing in el7
-generic/434	# xfs_io copy_range missing in el7
-generic/441	# dm-mapper
-generic/444	# el9's posix_acl_update_mode is buggy ?
-generic/467	# open_by_handle ESTALE
-generic/472	# swap
-generic/484	# dm-mapper
-generic/493	# swap
-generic/494	# swap
-generic/495	# swap
-generic/496	# swap
-generic/497	# swap
-generic/532	# xfs_io statx attrib_mask missing in el7
-generic/554	# swap
-generic/563	# cgroup+loopdev
-generic/564	# xfs_io copy_range missing in el7
-generic/565	# xfs_io copy_range missing in el7
-generic/568	# falloc not resulting in block count increase
-generic/569	# swap
-generic/570	# swap
-generic/620	# dm-hugedisk
-generic/633	# id-mapped mounts missing in el7
-generic/636	# swap
-generic/641	# swap
-generic/643	# swap
-EOF
+cp "$T_EXTRA/local.exclude" local.exclude
 
-t_restore_output
+t_stdout_invoked
 echo "  (showing output of xfstests)"
 
 args="-E local.exclude ${T_XFSTESTS_ARGS:--g quick}"
 ./check $args
 # the fs is unmounted when check finishes
 
+t_stdout_compare
+
 #
-# ./check writes the results of the run to check.log.  It lists
-# the tests it ran, skipped, or failed.  Then it writes a line saying
-# everything passed or some failed.  We scrape the most recent run and
-# use it as the output to compare to make sure that we run the right
-# tests and get the right results.
+# ./check writes the results of the run to check.log.  It lists the
+# tests it ran, skipped, or failed.  Then it writes a line saying
+# everything passed or some failed.
+#
+
+#
+# If XFSTESTS_ARGS were specified then we just pass/fail to match the
+# check run.
+#
+if [ -n "$T_XFSTESTS_ARGS" ]; then
+	if tail -1 results/check.log | grep -q "Failed"; then
+		t_fail
+	else
+		t_pass
+	fi
+fi
+
+#
+# Otherwise, typically, when there were no args then we scrape the most
+# recent run and use it as the output to compare to make sure that we
+# run the right tests and get the right results.
 #
 awk '
 	/^(Ran|Not run|Failures):.*/ {
 		if (pf) {
 			res=""
 			pf=""
-		} res = res "\n" $0
+		}
+		res = res "\n" $0
 	}
 	/^(Passed|Failed).*tests$/ {
 		pf=$0
@@ -139,10 +113,14 @@ awk '
 	}' < results/check.log  > "$T_TMPDIR/results"
 
 # put a test per line so diff shows tests that differ
-egrep "^(Ran|Not run|Failures):" "$T_TMPDIR/results" | \
-	fmt -w 1 > "$T_TMPDIR/results.fmt"
-egrep "^(Passed|Failed).*tests$" "$T_TMPDIR/results" >> "$T_TMPDIR/results.fmt"
+grep -E "^(Ran|Not run|Failures):" "$T_TMPDIR/results" | fmt -w 1 > "$T_TMPDIR/results.fmt"
+grep -E "^(Passed|Failed).*tests$" "$T_TMPDIR/results" >> "$T_TMPDIR/results.fmt"
 
-t_compare_output cat "$T_TMPDIR/results.fmt"
+diff -u "$T_EXTRA/expected-results" "$T_TMPDIR/results.fmt" > "$T_TMPDIR/results.diff"
+if [ -s "$T_TMPDIR/results.diff" ]; then
+	echo "tests that were skipped/run differed from expected:"
+	cat "$T_TMPDIR/results.diff"
+	t_fail
+fi
 
 t_pass

utils/fenced/scoutfs-fenced

@@ -62,31 +62,27 @@ test -x "$SCOUTFS_FENCED_RUN" || \
 # files disappear.
 #
 
-# generate failure messages to stderr while still echoing 0 for the caller
-careful_cat()
+# silence error messages
+quiet_cat()
 {
-	local path="$@"
-
-	cat "$@" || echo 0
+	cat "$@" 2>/dev/null
 }
 
 while sleep $SCOUTFS_FENCED_DELAY; do
+	shopt -s nullglob
 	for fence in /sys/fs/scoutfs/*/fence/*; do
-		# catches unmatched regex when no dirs
-		if [ ! -d "$fence" ]; then
-			continue
-		fi
-
-		# skip requests that have been handled
-		if [ "$(careful_cat $fence/fenced)" == 1 -o \
-		     "$(careful_cat $fence/error)" == 1 ]; then
-			continue
-		fi
 
 		srv=$(basename $(dirname $(dirname $fence)))
-		rid="$(cat $fence/rid)"
-		ip="$(cat $fence/ipv4_addr)"
-		reason="$(cat $fence/reason)"
+		fenced="$(quiet_cat $fence/fenced)"
+		error="$(quiet_cat $fence/error)"
+		rid="$(quiet_cat $fence/rid)"
+		ip="$(quiet_cat $fence/ipv4_addr)"
+		reason="$(quiet_cat $fence/reason)"
+
+		# request dirs can linger then disappear after fenced/error is set
+		if [ ! -d "$fence" -o "$fenced" == "1" -o "$error" == "1" ]; then
+			continue
+		fi
 
 		log_message "server $srv fencing rid $rid at IP $ip for $reason"
 

utils/man/scoutfs.5

@@ -55,6 +55,14 @@ with initial sparse regions (perhaps by multiple threads writing to
 different regions) and wasted space isn't an issue (perhaps because the
 file population contains few small files).
 .TP
+.B ino_alloc_per_lock=<number>
+This option determines how many inode numbers are allocated in the same
+cluster lock.  The default, and maximum, is 1024.  The minimum is 1.
+Allocating fewer inodes per lock can allow more parallelism between
+mounts because there are more locks that cover the same number of
+created files.  This can be helpful when working with smaller numbers of
+large files.
+.TP
 .B log_merge_wait_timeout_ms=<number>
 This option sets the amount of time, in milliseconds, that log merge
 creation can wait before timing out.  This setting is per-mount, only