Ramping up data preallocation

Ramps up data preallocation based on the number of online
blocks. This results in a simple 2<<n block allocation pattern
until n=11 (2048) - the default value of data_prealloc_blocks.

Signed-off-by: Auke Kok <auke.kok@versity.com>

kmod/src/data.c

@@ -384,6 +384,12 @@ static inline u64 ext_last(struct scoutfs_extent *ext)
  * This can waste a lot of space for small or sparse files but is
  * reasonable when a file population is known to be large and dense but
  * known to be written with non-streaming write patterns.
+ *
+ * In either strategy, preallocation ramps up proportionally with the
+ * file's online block count rather than jumping to the full prealloc
+ * size.  This avoids overallocation for small files in mixed-size
+ * workloads while still allowing large files to benefit from full
+ * preallocation.
  */
 static int alloc_block(struct super_block *sb, struct inode *inode,
 		       struct scoutfs_extent *ext, u64 iblock,
@@ -400,6 +406,7 @@ static int alloc_block(struct super_block *sb, struct inode *inode,
 	struct scoutfs_extent found;
 	struct scoutfs_extent pre = {0,};
 	bool undo_pre = false;
+	bool have_onoff = false;
 	u64 blkno = 0;
 	u64 online;
 	u64 offline;
@@ -445,6 +452,7 @@ static int alloc_block(struct super_block *sb, struct inode *inode,
 		 * blocks.
 		 */
 		scoutfs_inode_get_onoff(inode, &online, &offline);
+		have_onoff = true;
 		if (iblock > 1 && iblock == online) {
 			ret = scoutfs_ext_next(sb, &data_ext_ops, &args,
 					       iblock, 1, &found);
@@ -491,6 +499,16 @@ static int alloc_block(struct super_block *sb, struct inode *inode,
 	/* overall prealloc limit */
 	count = min_t(u64, count, opts.data_prealloc_blocks);
 
+	/*
+	 * Ramp preallocation up proportionally with the file's online
+	 * block count rather than jumping to the full prealloc size.
+	 */
+	if (!ext->len) {
+		if (!have_onoff)
+			scoutfs_inode_get_onoff(inode, &online, &offline);
+		count = max_t(u64, 1, min(count, online));
+	}
+
 	ret = scoutfs_alloc_data(sb, datinf->alloc, datinf->wri,
 				 &datinf->dalloc, count, &blkno, &count);
 	if (ret < 0)

kmod/src/scoutfs_trace.h

@@ -2620,60 +2620,24 @@ TRACE_EVENT(scoutfs_block_dirty_ref,
 );
 
 TRACE_EVENT(scoutfs_get_file_block,
-	TP_PROTO(struct super_block *sb, u64 blkno, int flags,
-		 struct scoutfs_srch_block *srb),
+	TP_PROTO(struct super_block *sb, u64 blkno, int flags),
 
-	TP_ARGS(sb, blkno, flags, srb),
+	TP_ARGS(sb, blkno, flags),
 
 	TP_STRUCT__entry(
 		SCSB_TRACE_FIELDS
 		__field(__u64, blkno)
-		__field(__u32, entry_nr)
-		__field(__u32, entry_bytes)
 		__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->entry_nr = __le32_to_cpu(srb->entry_nr);
-		__entry->entry_bytes = __le32_to_cpu(srb->entry_bytes);
 		__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 nr %u bytes %u flags 0x%x first_hash 0x%llx first_ino %llu first_id 0x%llx last_hash 0x%llx last_ino %llu last_id 0x%llx",
-		  SCSB_TRACE_ARGS, __entry->blkno, __entry->entry_nr,
-		  __entry->entry_bytes, __entry->flags,
-		  __entry->first_hash, __entry->first_ino, __entry->first_id,
-		  __entry->last_hash, __entry->last_ino, __entry->last_id)
-);
-
-TRACE_EVENT(scoutfs_srch_new_merge,
-	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)
+	TP_printk(SCSBF" blkno %llu flags 0x%x",
+		  SCSB_TRACE_ARGS, __entry->blkno, __entry->flags)
 );
 
 TRACE_EVENT(scoutfs_block_stale,

kmod/src/server.c

@@ -638,7 +638,7 @@ static void scoutfs_server_commit_func(struct work_struct *work)
 	ret = scoutfs_alloc_empty_list(sb, &server->alloc, &server->wri,
 				       server->meta_freed,
 				       server->other_freed);
-	if (ret && ret != -ENOLINK) {
+	if (ret) {
 		scoutfs_err(sb, "server error emptying freed: %d", ret);
 		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, bl->data);
+		trace_scoutfs_get_file_block(sb, bl->blkno, flags);
 	}
 
 	*bl_ret = bl;
@@ -1525,65 +1525,6 @@ static bool should_commit(struct super_block *sb, struct scoutfs_alloc *alloc,
 		scoutfs_alloc_meta_low(sb, alloc, nr);
 }
 
-static int alloc_srch_block(struct super_block *sb, struct scoutfs_alloc *alloc,
-			    struct scoutfs_block_writer *wri,
-			    struct scoutfs_srch_file *sfl,
-			    struct scoutfs_block **bl,
-			    u64 blk)
-{
-	DECLARE_SRCH_INFO(sb, srinf);
-	int ret;
-
-	if (atomic_read(&srinf->shutdown))
-		return -ESHUTDOWN;
-
-	/* could grow and dirty to a leaf */
-	if (should_commit(sb, alloc, wri, sfl->height + 1))
-		return -EAGAIN;
-
-	ret = get_file_block(sb, alloc, wri, sfl, GFB_INSERT | GFB_DIRTY,
-			     blk, bl);
-	if (ret < 0)
-		return ret;
-
-	scoutfs_inc_counter(sb, srch_compact_dirty_block);
-
-	return 0;
-}
-
-static int emit_srch_entry(struct super_block *sb,
-			   struct scoutfs_srch_file *sfl,
-			   struct scoutfs_srch_block *srb,
-			   struct scoutfs_srch_entry *sre,
-			   u64 blk)
-{
-	int ret;
-
-	ret = encode_entry(srb->entries + le32_to_cpu(srb->entry_bytes),
-			   sre, &srb->tail);
-	if (WARN_ON_ONCE(ret <= 0)) {
-		/* shouldn't happen */
-		return -EIO;
-	}
-
-	if (srb->entry_bytes == 0) {
-		if (blk == 0)
-			sfl->first = *sre;
-		srb->first = *sre;
-	}
-
-	le32_add_cpu(&srb->entry_nr, 1);
-	le32_add_cpu(&srb->entry_bytes, ret);
-	srb->last = *sre;
-	srb->tail = *sre;
-	sfl->last = *sre;
-	le64_add_cpu(&sfl->entries, 1);
-
-	scoutfs_inc_counter(sb, srch_compact_entry);
-
-	return 0;
-}
-
 struct tourn_node {
 	struct scoutfs_srch_entry sre;
 	int ind;
@@ -1606,8 +1547,7 @@ static void tourn_update(struct tourn_node *tnodes, struct tourn_node *tn)
 }
 
 /* return the entry at the current position, can return enoent if done */
-typedef int (*kway_get_t)(struct super_block *sb, struct scoutfs_alloc *alloc,
-			  struct scoutfs_block_writer *wri,
+typedef int (*kway_get_t)(struct super_block *sb,
 			  struct scoutfs_srch_entry *sre_ret, void *arg);
 /* only called after _get returns 0, advances to next entry for _get */
 typedef void (*kway_advance_t)(struct super_block *sb, void *arg);
@@ -1619,18 +1559,20 @@ static int kway_merge(struct super_block *sb,
 		      kway_get_t kway_get, kway_advance_t kway_adv,
 		      void **args, int nr, bool logs_input)
 {
+	DECLARE_SRCH_INFO(sb, srinf);
 	struct scoutfs_srch_block *srb = NULL;
-	struct scoutfs_srch_entry tmp_entry = {0};
+	struct scoutfs_srch_entry last_tail;
 	struct scoutfs_block *bl = NULL;
 	struct tourn_node *tnodes;
 	struct tourn_node *leaves;
 	struct tourn_node *root;
 	struct tourn_node *tn;
-	bool have_tmp = false;
+	int last_bytes = 0;
 	int nr_parents;
 	int nr_nodes;
 	int empty = 0;
 	int ret = 0;
+	int diff;
 	u64 blk;
 	int ind;
 	int i;
@@ -1654,7 +1596,7 @@ static int kway_merge(struct super_block *sb,
 	for (i = 0; i < nr; i++) {
 		tn = &leaves[i];
 		tn->ind = i;
-		ret = kway_get(sb, NULL, NULL, &tn->sre, args[i]);
+		ret = kway_get(sb, &tn->sre, args[i]);
 		if (ret == 0) {
 			tourn_update(tnodes, &leaves[i]);
 		} else if (ret == -ENOENT) {
@@ -1664,68 +1606,97 @@ static int kway_merge(struct super_block *sb,
 		}
 	}
 
-	trace_scoutfs_srch_new_merge(sb);
-
 	/* always append new blocks */
 	blk = le64_to_cpu(sfl->blocks);
 	while (empty < nr) {
-		if (sre_cmp(&root->sre, &tmp_entry) != 0) {
-			if (have_tmp) {
-				if (bl == NULL) {
-					ret = alloc_srch_block(sb, alloc, wri,
-							       sfl, &bl, blk);
-					if (ret < 0)
-						goto out;
-
-					srb = bl->data;
-				}
-
-				ret = emit_srch_entry(sb, sfl, srb, &tmp_entry,
-						      blk);
-				if (ret < 0)
-					goto out;
-
-				if (le32_to_cpu(srb->entry_bytes) >
-						SCOUTFS_SRCH_BLOCK_SAFE_BYTES) {
-					scoutfs_block_put(sb, bl);
-					bl = NULL;
-					blk++;
-					memset(&tmp_entry, 0, sizeof(tmp_entry));
-					have_tmp = false;
-					continue;
-				}
-
-				/*
-				 * end sorted block on _SAFE offset for
-				 * testing
-				 */
-				if (bl && le32_to_cpu(srb->entry_nr) == 1 &&
-				    logs_input &&
-				    scoutfs_trigger(sb, SRCH_COMPACT_LOGS_PAD_SAFE)) {
-					pad_entries_at_safe(sfl, srb);
-					scoutfs_block_put(sb, bl);
-					bl = NULL;
-					blk++;
-
-					memset(&tmp_entry, 0, sizeof(tmp_entry));
-					have_tmp = false;
-					continue;
-				}
+		if (bl == NULL) {
+			if (atomic_read(&srinf->shutdown)) {
+				ret = -ESHUTDOWN;
+				goto out;
 			}
 
-			tmp_entry = root->sre;
-			have_tmp = true;
+			/* could grow and dirty to a leaf */
+			if (should_commit(sb, alloc, wri, sfl->height + 1)) {
+				ret = 0;
+				goto out;
+			}
+
+			ret = get_file_block(sb, alloc, wri, sfl,
+					     GFB_INSERT | GFB_DIRTY, blk, &bl);
+			if (ret < 0)
+				goto out;
+			srb = bl->data;
+			scoutfs_inc_counter(sb, srch_compact_dirty_block);
+		}
+
+		if (sre_cmp(&root->sre, &srb->last) != 0) {
+			last_bytes = le32_to_cpu(srb->entry_bytes);
+			last_tail = srb->last;
+			ret = encode_entry(srb->entries +
+					   le32_to_cpu(srb->entry_bytes),
+					   &root->sre, &srb->tail);
+			if (WARN_ON_ONCE(ret <= 0)) {
+				/* shouldn't happen */
+				ret = -EIO;
+				goto out;
+			}
+
+			if (srb->entry_bytes == 0) {
+				if (blk == 0)
+					sfl->first = root->sre;
+				srb->first = root->sre;
+			}
+			le32_add_cpu(&srb->entry_nr, 1);
+			le32_add_cpu(&srb->entry_bytes, ret);
+			srb->last = root->sre;
+			srb->tail = root->sre;
+			sfl->last = root->sre;
+			le64_add_cpu(&sfl->entries, 1);
+			ret = 0;
+
+			if (le32_to_cpu(srb->entry_bytes) >
+			    SCOUTFS_SRCH_BLOCK_SAFE_BYTES) {
+				scoutfs_block_put(sb, bl);
+				bl = NULL;
+				blk++;
+			}
+
+			/* end sorted block on _SAFE offset for testing */
+			if (bl && le32_to_cpu(srb->entry_nr) == 1 && logs_input &&
+			    scoutfs_trigger(sb, SRCH_COMPACT_LOGS_PAD_SAFE)) {
+				pad_entries_at_safe(sfl, srb);
+				scoutfs_block_put(sb, bl);
+				bl = NULL;
+				blk++;
+			}
+
+			scoutfs_inc_counter(sb, srch_compact_entry);
+
 		} else {
 			/*
 			 * Duplicate entries indicate deletion so we
-			 * undo the previously cached tmp entry and ignore
+			 * undo the previously encoded entry and ignore
 			 * this entry.  This only happens within each
 			 * block.  Deletions can span block boundaries
 			 * and will be filtered out by search and
 			 * hopefully removed in future compactions.
 			 */
-			memset(&tmp_entry, 0, sizeof(tmp_entry));
-			have_tmp = false;
+			diff = le32_to_cpu(srb->entry_bytes) - last_bytes;
+			if (diff) {
+				memset(srb->entries + last_bytes, 0, diff);
+				if (srb->entry_bytes == 0) {
+					/* last_tail will be 0 */
+					if (blk == 0)
+						sfl->first = last_tail;
+					srb->first = last_tail;
+				}
+				le32_add_cpu(&srb->entry_nr, -1);
+				srb->entry_bytes = cpu_to_le32(last_bytes);
+				srb->last = last_tail;
+				srb->tail = last_tail;
+				sfl->last = last_tail;
+				le64_add_cpu(&sfl->entries, -1);
+			}
 
 			scoutfs_inc_counter(sb, srch_compact_removed_entry);
 		}
@@ -1734,7 +1705,7 @@ static int kway_merge(struct super_block *sb,
 		ind = root->ind;
 		tn = &leaves[ind];
 		kway_adv(sb, args[ind]);
-		ret = kway_get(sb, alloc, wri, &tn->sre, args[ind]);
+		ret = kway_get(sb, &tn->sre, args[ind]);
 		if (ret == -ENOENT) {
 			/* this index is done */
 			memset(&tn->sre, 0xff, sizeof(tn->sre));
@@ -1768,21 +1739,6 @@ static int kway_merge(struct super_block *sb,
 	/* could stream a final index.. arguably a small portion of work */
 
 out:
-	if (have_tmp) {
-		bool emit = true;
-
-		if (bl == NULL) {
-			ret = alloc_srch_block(sb, alloc, wri, sfl, &bl, blk);
-			if (ret)
-				emit = false;
-			else
-				srb = bl->data;
-		}
-
-		if (emit)
-			ret = emit_srch_entry(sb, sfl, srb, &tmp_entry, blk);
-	}
-
 	scoutfs_block_put(sb, bl);
 	vfree(tnodes);
 	return ret;
@@ -1795,8 +1751,7 @@ static struct scoutfs_srch_entry *page_priv_sre(struct page *page)
 	return (struct scoutfs_srch_entry *)page_address(page) + page->private;
 }
 
-static int kway_get_page(struct super_block *sb, struct scoutfs_alloc *alloc,
-			 struct scoutfs_block_writer *wri,
+static int kway_get_page(struct super_block *sb,
 			 struct scoutfs_srch_entry *sre_ret, void *arg)
 {
 	struct page *page = arg;
@@ -2003,8 +1958,7 @@ struct kway_file_reader {
 	int decoded_bytes;
 };
 
-static int kway_get_reader(struct super_block *sb, struct scoutfs_alloc *alloc,
-			   struct scoutfs_block_writer *wri,
+static int kway_get_reader(struct super_block *sb,
 			   struct scoutfs_srch_entry *sre_ret, void *arg)
 {
 	struct kway_file_reader *rdr = arg;
@@ -2015,17 +1969,6 @@ static int kway_get_reader(struct super_block *sb, struct scoutfs_alloc *alloc,
 		return -ENOENT;
 
 	if (rdr->bl == NULL) {
-		/*
-		 * Each new output block has the possibility of winding up with
-		 * a straggler entry due to our need to look ahead an entry so
-		 * that we don't wind up emitting an empty block.
-		 *
-		 * Make sure there's space to emit the straggler before starting
-		 * another input block.
-		 */
-		if (alloc && should_commit(sb, alloc, wri, 16))
-			return -ENOENT;
-
 		ret = get_file_block(sb, NULL, NULL, rdr->sfl, 0, rdr->blk,
 				     &rdr->bl);
 		if (ret < 0)
@@ -2039,11 +1982,6 @@ static int kway_get_reader(struct super_block *sb, struct scoutfs_alloc *alloc,
 	    rdr->skip > SCOUTFS_SRCH_BLOCK_SAFE_BYTES ||
 	    rdr->skip >= le32_to_cpu(srb->entry_bytes)) {
 		/* XXX inconsistency */
-		scoutfs_err(sb, "blkno %llu pos %u vs %ld, skip %u, bytes %u",
-			__le64_to_cpu(srb->hdr.blkno),
-			rdr->pos, SCOUTFS_SRCH_BLOCK_SAFE_BYTES,
-			rdr->skip,
-			le32_to_cpu(srb->entry_bytes));
 		return -EIO;
 	}
 

tests/golden/data-prealloc

@@ -8,10 +8,10 @@
 /mnt/test/test/data-prealloc/file-1: extents: 32
 /mnt/test/test/data-prealloc/file-2: extents: 32
 == any writes to region prealloc get full extents
-/mnt/test/test/data-prealloc/file-1: extents: 4
-/mnt/test/test/data-prealloc/file-2: extents: 4
-/mnt/test/test/data-prealloc/file-1: extents: 4
-/mnt/test/test/data-prealloc/file-2: extents: 4
+/mnt/test/test/data-prealloc/file-1: extents: 8
+/mnt/test/test/data-prealloc/file-2: extents: 8
+/mnt/test/test/data-prealloc/file-1: extents: 8
+/mnt/test/test/data-prealloc/file-2: extents: 8
 == streaming offline writes get full extents either way
 /mnt/test/test/data-prealloc/file-1: extents: 4
 /mnt/test/test/data-prealloc/file-2: extents: 4
@@ -20,8 +20,8 @@
 == goofy preallocation amounts work
 /mnt/test/test/data-prealloc/file-1: extents: 6
 /mnt/test/test/data-prealloc/file-2: extents: 6
-/mnt/test/test/data-prealloc/file-1: extents: 6
-/mnt/test/test/data-prealloc/file-2: extents: 6
+/mnt/test/test/data-prealloc/file-1: extents: 10
+/mnt/test/test/data-prealloc/file-2: extents: 10
 /mnt/test/test/data-prealloc/file-1: extents: 3
 /mnt/test/test/data-prealloc/file-2: extents: 3
 == block writes into region allocs hole

tests/golden/srch-safe-merge-pos

@@ -1,7 +1,37 @@
 == 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/run-tests.sh

@@ -90,7 +90,7 @@ done
 
 # set some T_ defaults
 T_TRACE_DUMP="0"
-T_TRACE_PRINTK=""
+T_TRACE_PRINTK="0"
 T_PORT_START="19700"
 T_LOOP_ITER="1"
 
@@ -137,9 +137,6 @@ 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)
@@ -402,44 +399,31 @@ if [ -n "$T_INSMOD" ]; then
 	cmd insmod "$T_MODULE"
 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
+if [ -n "$T_TRACE_MULT" ]; then
+#	orig_trace_size=$(cat /sys/kernel/debug/tracing/buffer_size_kb)
+	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
-			done
+	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
 
-		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
-}
+	nr_events=$(cat /sys/kernel/debug/tracing/set_event | wc -l)
+	msg "enabled $nr_events trace events from $nr_globs -t globs"
+fi
 
 if [ -n "$T_TRACE_PRINTK" ]; then
 	echo "$T_TRACE_PRINTK" > /sys/kernel/debug/tracing/options/trace_printk
@@ -619,26 +603,24 @@ passed=0
 skipped=0
 failed=0
 skipped_permitted=0
-for iter in $(seq 1 $T_LOOP_ITER); do
+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$//')
 
-	start_tracing
+	# 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"
 
-	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$//')
+	# mark in dmesg as to what test we are running
+	echo "run scoutfs test $test_name" > /dev/kmsg
 
-		# 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"
+	# let the test get at its extra files
+	T_EXTRA="$T_TESTS/extra/$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"
+	for iter in $(seq 1 $T_LOOP_ITER); do
 
 		# create a temporary dir and file path for the test
 		T_TMPDIR="$T_RESULTS/tmp/$test_name"
@@ -728,43 +710,55 @@ for iter in $(seq 1 $T_LOOP_ITER); do
 			sts=$T_FAIL_STATUS
 		fi
 
-		# 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
+		# stop looping if we didn't pass
+		if [ "$sts" != "$T_PASS_STATUS" ]; then
+			break;
 		fi
-
-		# record results for TAP format output
-		t_tap_progress $test_name $sts
-		((testcount++))
 	done
 
-	stop_tracing
+	# 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++))
+
 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/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_silent srch_compact_logs_pad_safe $nr
-	t_trigger_arm_silent srch_merge_stop_safe $nr
+	t_trigger_arm srch_compact_logs_pad_safe $nr
+	t_trigger_arm srch_merge_stop_safe $nr
 done
 
 echo "== compact more often"
@@ -44,12 +44,11 @@ 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
+
 		seq -f "f-$i-$j-$SEQF" 1 10 | \
 			bulk_create_paths -X "scoutfs.srch.t-srch-safe-merge-pos" -d "$T_D0" > \
 			/dev/null
-
-		t_trigger_arm_silent srch_force_log_rotate $sv
-
 		sync
 
 		test "$(t_trigger_get srch_force_log_rotate $sv)" == "0" || \
@@ -60,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_silent srch_compact_logs_pad_safe $nr
+				t_trigger_arm srch_compact_logs_pad_safe $nr
 				padded=1
 				break
 			fi