tempfile: make sure FS_COMPR_FL stays set

btrfs will set the FS_NOCOMP_FL flag when all of the following are true:

1.  The filesystem is not mounted with the `compress-force` option
2.  Heuristic analysis of the data suggests the data is compressible
3.  Compression fails to produce a result that is smaller than the original

If the compression ratio is 40%, and the original data is 128K long,
then compressed data will be about 52K long (rounded up to 4K), so item
3 is usually false; however, if the original data is 8K long, then the
compressed data will be 8K long too, and btrfs will set FS_NOCOMP_FL.

To work around that, keep setting FS_COMPR_FL and clearing FS_NOCOMP_FL
every time a TempFile is reset.

Signed-off-by: Zygo Blaxell <bees@furryterror.org>

docs/btrfs-kernel.md

@@ -55,6 +55,7 @@ These bugs are particularly popular among bees users, though not all are specifi
 | 5.4 | 5.11 | spurious tree checker failures on extent ref hash | 5.4.125, 5.10.43, 5.11.5, 5.12 and later | 1119a72e223f btrfs: tree-checker: do not error out if extent ref hash doesn't match
 | - | 5.11 | tree mod log issue #5 | 4.4.263, 4.9.263, 4.14.227, 4.19.183, 5.4.108, 5.10.26, 5.11.9, 5.12 and later | dbcc7d57bffc btrfs: fix race when cloning extent buffer during rewind of an old root
 | - | 5.12 | tree mod log issue #6 | 4.14.233, 4.19.191, 5.4.118, 5.10.36, 5.11.20, 5.12.3, 5.13 and later | f9690f426b21 btrfs: fix race when picking most recent mod log operation for an old root
+| 5.11 | 5.12 | subvols marked for deletion with `btrfs sub del` become permanently undeletable ("ghost" subvols) | 5.12 stopped creation of new ghost subvols | Partially fixed in 8d488a8c7ba2 btrfs: fix subvolume/snapshot deletion not triggered on mount.  Qu wrote a [patch](https://github.com/adam900710/linux/commit/9de990fcc8864c376eb28aa7482c54321f94acd4) to allow `btrfs sub del -i` to remove "ghost" subvols, but it was never merged upstream.
 | 4.15 | 5.16 | spurious warnings from `fs/fs-writeback.c` when `flushoncommit` is enabled | 5.15.27, 5.16.13, 5.17 and later | a0f0cf8341e3 btrfs: get rid of warning on transaction commit when using flushoncommit
 | - | 5.17 | crash during device removal can make filesystem unmountable | 5.15.54, 5.16.20, 5.17.3, 5.18 and later | bbac58698a55 btrfs: remove device item and update super block in the same transaction
 | - | 5.18 | wrong superblock num_devices makes filesystem unmountable | 4.14.283, 4.19.247, 5.4.198, 5.10.121, 5.15.46, 5.17.14, 5.18.3, 5.19 and later | d201238ccd2f btrfs: repair super block num_devices automatically

include/crucible/btrfs.h

@@ -78,9 +78,6 @@ enum btrfs_compression_type {
 	#define BTRFS_SHARED_BLOCK_REF_KEY      182
 	#define BTRFS_SHARED_DATA_REF_KEY       184
 	#define BTRFS_BLOCK_GROUP_ITEM_KEY 192
-	#define BTRFS_FREE_SPACE_INFO_KEY 198
-	#define BTRFS_FREE_SPACE_EXTENT_KEY 199
-	#define BTRFS_FREE_SPACE_BITMAP_KEY 200
 	#define BTRFS_DEV_EXTENT_KEY    204
 	#define BTRFS_DEV_ITEM_KEY      216
 	#define BTRFS_CHUNK_ITEM_KEY    228
@@ -97,6 +94,18 @@ enum btrfs_compression_type {
 
 #endif
 
+#ifndef BTRFS_FREE_SPACE_INFO_KEY
+	#define BTRFS_FREE_SPACE_INFO_KEY 198
+	#define BTRFS_FREE_SPACE_EXTENT_KEY 199
+	#define BTRFS_FREE_SPACE_BITMAP_KEY 200
+	#define BTRFS_FREE_SPACE_OBJECTID -11ULL
+#endif
+
+#ifndef BTRFS_BLOCK_GROUP_RAID1C4
+	#define BTRFS_BLOCK_GROUP_RAID1C3       (1ULL << 9)
+	#define BTRFS_BLOCK_GROUP_RAID1C4       (1ULL << 10)
+#endif
+
 #ifndef BTRFS_DEFRAG_RANGE_START_IO
 
 	// For some reason uapi has BTRFS_DEFRAG_RANGE_COMPRESS and

include/crucible/hexdump.h

@@ -13,7 +13,7 @@ namespace crucible {
 	hexdump(ostream &os, const V &v)
 	{
 		const auto v_size = v.size();
-		const uint8_t* const v_data = reinterpret_cast<uint8_t*>(v.data());
+		const uint8_t* const v_data = reinterpret_cast<const uint8_t*>(v.data());
 		os << "V { size = " << v_size << ", data:\n";
 		for (size_t i = 0; i < v_size; i += 8) {
 			string hex, ascii;

include/crucible/seeker.h

@@ -6,23 +6,23 @@
 #include <algorithm>
 #include <limits>
 
-#include <cstdint>
-
-#if 0
+// Debug stream
+#include <memory>
 #include <iostream>
 #include <sstream>
-#define DINIT(__x) __x
-#define DLOG(__x) do { logs << __x << std::endl; } while (false)
-#define DOUT(__err) do { __err << logs.str(); } while (false)
-#else
-#define DINIT(__x) do {} while (false)
-#define DLOG(__x) do {} while (false)
-#define DOUT(__x) do {} while (false)
-#endif
+
+#include <cstdint>
 
 namespace crucible {
 	using namespace std;
 
+	extern thread_local shared_ptr<ostream> tl_seeker_debug_str;
+	#define SEEKER_DEBUG_LOG(__x) do { \
+		if (tl_seeker_debug_str) { \
+			(*tl_seeker_debug_str) << __x << "\n"; \
+		} \
+	} while (false)
+
 	// Requirements for Container<Pos> Fetch(Pos lower, Pos upper):
 	// - fetches objects in Pos order, starting from lower (must be >= lower)
 	// - must return upper if present, may or may not return objects after that
@@ -49,113 +49,108 @@ namespace crucible {
 	Pos
 	seek_backward(Pos const target_pos, Fetch fetch, Pos min_step = 1, size_t max_loops = numeric_limits<size_t>::max())
 	{
-		DINIT(ostringstream logs);
-		try {
-			static const Pos end_pos = numeric_limits<Pos>::max();
-			// TBH this probably won't work if begin_pos != 0, i.e. any signed type
-			static const Pos begin_pos = numeric_limits<Pos>::min();
-			// Run a binary search looking for the highest key below target_pos.
-			// Initial upper bound of the search is target_pos.
-			// Find initial lower bound by doubling the size of the range until a key below target_pos
-			// is found, or the lower bound reaches the beginning of the search space.
-			// If the lower bound search reaches the beginning of the search space without finding a key,
-			// return the beginning of the search space; otherwise, perform a binary search between
-			// the bounds now established.
-			Pos lower_bound = 0;
-			Pos upper_bound = target_pos;
-			bool found_low = false;
-			Pos probe_pos = target_pos;
-			// We need one loop for each bit of the search space to find the lower bound,
-			// one loop for each bit of the search space to find the upper bound,
-			// and one extra loop to confirm the boundary is correct.
-			for (size_t loop_count = min(numeric_limits<Pos>::digits * size_t(2) + 1, max_loops); loop_count; --loop_count) {
-				DLOG("fetch(probe_pos = " << probe_pos << ", target_pos = " << target_pos << ")");
-				auto result = fetch(probe_pos, target_pos);
-				const Pos low_pos = result.empty() ? end_pos : *result.begin();
-				const Pos high_pos = result.empty() ? end_pos : *result.rbegin();
-				DLOG(" = " << low_pos << ".." << high_pos);
-				// check for correct behavior of the fetch function
-				THROW_CHECK2(out_of_range, high_pos, probe_pos, probe_pos <= high_pos);
-				THROW_CHECK2(out_of_range, low_pos, probe_pos, probe_pos <= low_pos);
-				THROW_CHECK2(out_of_range, low_pos, high_pos, low_pos <= high_pos);
-				if (!found_low) {
-					// if target_pos == end_pos then we will find it in every empty result set,
-					// so in that case we force the lower bound to be lower than end_pos
-					if ((target_pos == end_pos) ? (low_pos < target_pos) : (low_pos <= target_pos)) {
-						// found a lower bound, set the low bound there and switch to binary search
-						found_low = true;
-						lower_bound = low_pos;
-						DLOG("found_low = true, lower_bound = " << lower_bound);
-					} else {
-						// still looking for lower bound
-						// if probe_pos was begin_pos then we can stop with no result
-						if (probe_pos == begin_pos) {
-							DLOG("return: probe_pos == begin_pos " << begin_pos);
-							return begin_pos;
-						}
-						// double the range size, or use the distance between objects found so far
-						THROW_CHECK2(out_of_range, upper_bound, probe_pos, probe_pos <= upper_bound);
-						// already checked low_pos <= high_pos above
-						const Pos want_delta = max(upper_bound - probe_pos, min_step);
-						// avoid underflowing the beginning of the search space
-						const Pos have_delta = min(want_delta, probe_pos - begin_pos);
-						THROW_CHECK2(out_of_range, want_delta, have_delta, have_delta <= want_delta);
-						// move probe and try again
-						probe_pos = probe_pos - have_delta;
-						DLOG("probe_pos " << probe_pos << " = probe_pos - have_delta " << have_delta << " (want_delta " << want_delta << ")");
-						continue;
+		static const Pos end_pos = numeric_limits<Pos>::max();
+		// TBH this probably won't work if begin_pos != 0, i.e. any signed type
+		static const Pos begin_pos = numeric_limits<Pos>::min();
+		// Run a binary search looking for the highest key below target_pos.
+		// Initial upper bound of the search is target_pos.
+		// Find initial lower bound by doubling the size of the range until a key below target_pos
+		// is found, or the lower bound reaches the beginning of the search space.
+		// If the lower bound search reaches the beginning of the search space without finding a key,
+		// return the beginning of the search space; otherwise, perform a binary search between
+		// the bounds now established.
+		Pos lower_bound = 0;
+		Pos upper_bound = target_pos;
+		bool found_low = false;
+		Pos probe_pos = target_pos;
+		// We need one loop for each bit of the search space to find the lower bound,
+		// one loop for each bit of the search space to find the upper bound,
+		// and one extra loop to confirm the boundary is correct.
+		for (size_t loop_count = min((1 + numeric_limits<Pos>::digits) * size_t(2), max_loops); loop_count; --loop_count) {
+			SEEKER_DEBUG_LOG("fetch(probe_pos = " << probe_pos << ", target_pos = " << target_pos << ")");
+			auto result = fetch(probe_pos, target_pos);
+			const Pos low_pos = result.empty() ? end_pos : *result.begin();
+			const Pos high_pos = result.empty() ? end_pos : *result.rbegin();
+			SEEKER_DEBUG_LOG(" = " << low_pos << ".." << high_pos);
+			// check for correct behavior of the fetch function
+			THROW_CHECK2(out_of_range, high_pos, probe_pos, probe_pos <= high_pos);
+			THROW_CHECK2(out_of_range, low_pos, probe_pos, probe_pos <= low_pos);
+			THROW_CHECK2(out_of_range, low_pos, high_pos, low_pos <= high_pos);
+			if (!found_low) {
+				// if target_pos == end_pos then we will find it in every empty result set,
+				// so in that case we force the lower bound to be lower than end_pos
+				if ((target_pos == end_pos) ? (low_pos < target_pos) : (low_pos <= target_pos)) {
+					// found a lower bound, set the low bound there and switch to binary search
+					found_low = true;
+					lower_bound = low_pos;
+					SEEKER_DEBUG_LOG("found_low = true, lower_bound = " << lower_bound);
+				} else {
+					// still looking for lower bound
+					// if probe_pos was begin_pos then we can stop with no result
+					if (probe_pos == begin_pos) {
+						SEEKER_DEBUG_LOG("return: probe_pos == begin_pos " << begin_pos);
+						return begin_pos;
 					}
+					// double the range size, or use the distance between objects found so far
+					THROW_CHECK2(out_of_range, upper_bound, probe_pos, probe_pos <= upper_bound);
+					// already checked low_pos <= high_pos above
+					const Pos want_delta = max(upper_bound - probe_pos, min_step);
+					// avoid underflowing the beginning of the search space
+					const Pos have_delta = min(want_delta, probe_pos - begin_pos);
+					THROW_CHECK2(out_of_range, want_delta, have_delta, have_delta <= want_delta);
+					// move probe and try again
+					probe_pos = probe_pos - have_delta;
+					SEEKER_DEBUG_LOG("probe_pos " << probe_pos << " = probe_pos - have_delta " << have_delta << " (want_delta " << want_delta << ")");
+					continue;
 				}
-				if (low_pos <= target_pos && target_pos <= high_pos) {
-					// have keys on either side of target_pos in result
-					// search from the high end until we find the highest key below target
-					for (auto i = result.rbegin(); i != result.rend(); ++i) {
-						// more correctness checking for fetch
-						THROW_CHECK2(out_of_range, *i, probe_pos, probe_pos <= *i);
-						if (*i <= target_pos) {
-							DLOG("return: *i " << *i << " <= target_pos " << target_pos);
-							return *i;
-						}
-					}
-					// if the list is empty then low_pos = high_pos = end_pos
-					// if target_pos = end_pos also, then we will execute the loop
-					// above but not find any matching entries.
-					THROW_CHECK0(runtime_error, result.empty());
-				}
-				if (target_pos <= low_pos) {
-					// results are all too high, so probe_pos..low_pos is too high
-					// lower the high bound to the probe pos
-					upper_bound = probe_pos;
-					DLOG("upper_bound = probe_pos " << probe_pos);
-				}
-				if (high_pos < target_pos) {
-					// results are all too low, so probe_pos..high_pos is too low
-					// raise the low bound to the high_pos
-					DLOG("lower_bound = high_pos " << high_pos);
-					lower_bound = high_pos;
-				}
-				// compute a new probe pos at the middle of the range and try again
-				// we can't have a zero-size range here because we would not have set found_low yet
-				THROW_CHECK2(out_of_range, lower_bound, upper_bound, lower_bound <= upper_bound);
-				const Pos delta = (upper_bound - lower_bound) / 2;
-				probe_pos = lower_bound + delta;
-				if (delta < 1) {
-					// nothing can exist in the range (lower_bound, upper_bound)
-					// and an object is known to exist at lower_bound
-					DLOG("return: probe_pos == lower_bound " << lower_bound);
-					return lower_bound;
-				}
-				THROW_CHECK2(out_of_range, lower_bound, probe_pos, lower_bound <= probe_pos);
-				THROW_CHECK2(out_of_range, upper_bound, probe_pos, probe_pos <= upper_bound);
-				DLOG("loop: lower_bound " << lower_bound << ", probe_pos " << probe_pos << ", upper_bound " << upper_bound);
 			}
-			THROW_ERROR(runtime_error, "FIXME: should not reach this line: "
-				"lower_bound..upper_bound " << lower_bound << ".." << upper_bound << ", "
-				"found_low " << found_low);
-		} catch (...) {
-			DOUT(cerr);
-			throw;
+			if (low_pos <= target_pos && target_pos <= high_pos) {
+				// have keys on either side of target_pos in result
+				// search from the high end until we find the highest key below target
+				for (auto i = result.rbegin(); i != result.rend(); ++i) {
+					// more correctness checking for fetch
+					THROW_CHECK2(out_of_range, *i, probe_pos, probe_pos <= *i);
+					if (*i <= target_pos) {
+						SEEKER_DEBUG_LOG("return: *i " << *i << " <= target_pos " << target_pos);
+						return *i;
+					}
+				}
+				// if the list is empty then low_pos = high_pos = end_pos
+				// if target_pos = end_pos also, then we will execute the loop
+				// above but not find any matching entries.
+				THROW_CHECK0(runtime_error, result.empty());
+			}
+			if (target_pos <= low_pos) {
+				// results are all too high, so probe_pos..low_pos is too high
+				// lower the high bound to the probe pos, low_pos cannot be lower
+				SEEKER_DEBUG_LOG("upper_bound = probe_pos " << probe_pos);
+				upper_bound = probe_pos;
+			}
+			if (high_pos < target_pos) {
+				// results are all too low, so probe_pos..high_pos is too low
+				// raise the low bound to high_pos but not above upper_bound
+				const auto next_pos = min(high_pos, upper_bound);
+				SEEKER_DEBUG_LOG("lower_bound = next_pos " << next_pos);
+				lower_bound = next_pos;
+			}
+			// compute a new probe pos at the middle of the range and try again
+			// we can't have a zero-size range here because we would not have set found_low yet
+			THROW_CHECK2(out_of_range, lower_bound, upper_bound, lower_bound <= upper_bound);
+			const Pos delta = (upper_bound - lower_bound) / 2;
+			probe_pos = lower_bound + delta;
+			if (delta < 1) {
+				// nothing can exist in the range (lower_bound, upper_bound)
+				// and an object is known to exist at lower_bound
+				SEEKER_DEBUG_LOG("return: probe_pos == lower_bound " << lower_bound);
+				return lower_bound;
+			}
+			THROW_CHECK2(out_of_range, lower_bound, probe_pos, lower_bound <= probe_pos);
+			THROW_CHECK2(out_of_range, upper_bound, probe_pos, probe_pos <= upper_bound);
+			SEEKER_DEBUG_LOG("loop bottom: lower_bound " << lower_bound << ", probe_pos " << probe_pos << ", upper_bound " << upper_bound);
 		}
+		THROW_ERROR(runtime_error, "FIXME: should not reach this line: "
+			"lower_bound..upper_bound " << lower_bound << ".." << upper_bound << ", "
+			"found_low " << found_low);
 	}
 }
 

lib/Makefile

@@ -17,6 +17,7 @@ CRUCIBLE_OBJS = \
 	openat2.o \
 	path.o \
 	process.o \
+	seeker.o \
 	string.o \
 	table.o \
 	task.o \

lib/btrfs-tree.cc

@@ -418,6 +418,7 @@ namespace crucible {
 			++loops;
 			fill_sk(sk, unscale_logical(min(scaled_max_logical(), lower_bound)));
 			set<uint64_t> rv;
+			bool too_far = false;
 			do {
 				sk.nr_items = 4;
 				sk.do_ioctl(fd());
@@ -426,6 +427,7 @@ namespace crucible {
 					next_sk(sk, i);
 					// If hdr_stop or !hdr_match, don't inspect the item
 					if (hdr_stop(i)) {
+						too_far = true;
 						rv.insert(numeric_limits<uint64_t>::max());
 						BTFRLB_DEBUG("(stop)");
 						break;
@@ -438,22 +440,23 @@ namespace crucible {
 					BTFRLB_DEBUG(" " << to_hex(this_logical) << " " << i);
 					const auto scaled_hdr_logical = scale_logical(this_logical);
 					BTFRLB_DEBUG(" " << "(match)");
+					if (scaled_hdr_logical > upper_bound) {
+						too_far = true;
+						BTFRLB_DEBUG("(" << to_hex(scaled_hdr_logical) << " >= " << to_hex(upper_bound) << ")");
+						break;
+					}
 					if (this_logical <= logical && this_logical > closest_logical) {
 						closest_logical = this_logical;
 						closest_item = i;
 						BTFRLB_DEBUG("(closest)");
 					}
 					rv.insert(scaled_hdr_logical);
-					if (scaled_hdr_logical > upper_bound) {
-						BTFRLB_DEBUG("(" << to_hex(scaled_hdr_logical) << " >= " << to_hex(upper_bound) << ")");
-						break;
-					}
 					BTFRLB_DEBUG("(cont'd)");
 				}
 				BTFRLB_DEBUG(endl);
 				// We might get a search result that contains only non-matching items.
 				// Keep looping until we find any matching item or we run out of tree.
-			} while (rv.empty() && !sk.m_result.empty());
+			} while (!too_far && rv.empty() && !sk.m_result.empty());
 			return rv;
 		}, scale_logical(lookbehind_size()));
 		return closest_item;

lib/fs.cc

@@ -932,15 +932,9 @@ namespace crucible {
 			NTOA_TABLE_ENTRY_ENUM(BTRFS_SHARED_BLOCK_REF_KEY),
 			NTOA_TABLE_ENTRY_ENUM(BTRFS_SHARED_DATA_REF_KEY),
 			NTOA_TABLE_ENTRY_ENUM(BTRFS_BLOCK_GROUP_ITEM_KEY),
-#ifdef BTRFS_FREE_SPACE_INFO_KEY
 			NTOA_TABLE_ENTRY_ENUM(BTRFS_FREE_SPACE_INFO_KEY),
-#endif
-#ifdef BTRFS_FREE_SPACE_EXTENT_KEY
 			NTOA_TABLE_ENTRY_ENUM(BTRFS_FREE_SPACE_EXTENT_KEY),
-#endif
-#ifdef BTRFS_FREE_SPACE_BITMAP_KEY
 			NTOA_TABLE_ENTRY_ENUM(BTRFS_FREE_SPACE_BITMAP_KEY),
-#endif
 			NTOA_TABLE_ENTRY_ENUM(BTRFS_DEV_EXTENT_KEY),
 			NTOA_TABLE_ENTRY_ENUM(BTRFS_DEV_ITEM_KEY),
 			NTOA_TABLE_ENTRY_ENUM(BTRFS_CHUNK_ITEM_KEY),
@@ -972,9 +966,7 @@ namespace crucible {
 			NTOA_TABLE_ENTRY_ENUM(BTRFS_CSUM_TREE_OBJECTID),
 			NTOA_TABLE_ENTRY_ENUM(BTRFS_QUOTA_TREE_OBJECTID),
 			NTOA_TABLE_ENTRY_ENUM(BTRFS_UUID_TREE_OBJECTID),
-#ifdef BTRFS_FREE_SPACE_TREE_OBJECTID
 			NTOA_TABLE_ENTRY_ENUM(BTRFS_FREE_SPACE_TREE_OBJECTID),
-#endif
 			NTOA_TABLE_ENTRY_ENUM(BTRFS_BALANCE_OBJECTID),
 			NTOA_TABLE_ENTRY_ENUM(BTRFS_ORPHAN_OBJECTID),
 			NTOA_TABLE_ENTRY_ENUM(BTRFS_TREE_LOG_OBJECTID),

lib/seeker.cc

@@ -0,0 +1,7 @@
+#include "crucible/seeker.h"
+
+namespace crucible {
+
+	thread_local shared_ptr<ostream> tl_seeker_debug_str;
+
+};

scripts/beesd@.service.in

@@ -17,6 +17,7 @@ KillSignal=SIGTERM
 MemoryAccounting=true
 Nice=19
 Restart=on-abnormal
+RuntimeDirectoryMode=0700
 RuntimeDirectory=bees
 StartupCPUWeight=25
 StartupIOWeight=25

src/bees-context.cc

@@ -230,8 +230,10 @@ BeesContext::dedup(const BeesRangePair &brp_in)
 	BeesAddress first_addr(brp.first.fd(), brp.first.begin());
 	BeesAddress second_addr(brp.second.fd(), brp.second.begin());
 
-	if (first_addr.get_physical_or_zero() == second_addr.get_physical_or_zero()) {
-		BEESLOGTRACE("equal physical addresses in dedup");
+	const auto first_gpoz = first_addr.get_physical_or_zero();
+	const auto second_gpoz = second_addr.get_physical_or_zero();
+	if (first_gpoz == second_gpoz) {
+		BEESLOGDEBUG("equal physical addresses " << first_addr << " and " << second_addr << " in dedup");
 		BEESCOUNT(bug_dedup_same_physical);
 	}
 
@@ -385,7 +387,7 @@ BeesContext::scan_one_extent(const BeesFileRange &bfr, const Extent &e)
 	if (e.flags() & Extent::PREALLOC) {
 		// Prealloc is all zero and we replace it with a hole.
 		// No special handling is required here.  Nuke it and move on.
-		BEESLOGINFO("prealloc extent " << e);
+		BEESLOGINFO("prealloc extent " << e << " in " << bfr);
 		// Must not extend past EOF
 		auto extent_size = min(e.end(), bfr.file_size()) - e.begin();
 		// Must hold tmpfile until dedupe is done

src/bees-hash.cc

@@ -819,7 +819,8 @@ BeesHashTable::BeesHashTable(shared_ptr<BeesContext> ctx, string filename, off_t
 		root_info.do_ioctl(m_ctx->root_fd());
 		// Hash might not be a btrfs
 		BtrfsIoctlFsInfoArgs hash_info;
-		if (hash_info.do_ioctl_nothrow(m_fd)) return;
+		// If btrfs fs_info ioctl fails, it must be a different fs
+		if (!hash_info.do_ioctl_nothrow(m_fd)) return;
 		// If Hash is a btrfs, Root must be the same one
 		if (root_info.fsid() != hash_info.fsid()) return;
 		// Hash is on the same one, blacklist it

src/bees-roots.cc

@@ -5,6 +5,7 @@
 #include "crucible/cleanup.h"
 #include "crucible/ntoa.h"
 #include "crucible/openat2.h"
+#include "crucible/seeker.h"
 #include "crucible/string.h"
 #include "crucible/table.h"
 #include "crucible/task.h"
@@ -780,10 +781,6 @@ BeesScanModeExtent::SizeTier::create_extent_map(const uint64_t bytenr, const Pro
 
 	BtrfsExtentDataFetcher bedf(m_ctx->root_fd());
 
-	// Collect extent ref tasks as a series of stand-alone events
-	// chained after the first task created, then run the first one.
-	// This prevents other threads from starting to process an
-	// extent until we have all of its refs in the queue.
 	const auto refs_list = make_shared<list<ExtentRef>>();
 	for (const auto &i : log_ino.m_iors) {
 		catch_all([&](){
@@ -899,6 +896,9 @@ BeesScanModeExtent::scan()
 {
 	BEESTRACE("bsm scan");
 
+	// Do nothing if we are throttled
+	if (should_throttle()) return;
+
 	unique_lock<mutex> lock(m_mutex);
 	const auto size_tiers_copy = m_size_tiers;
 	lock.unlock();
@@ -934,12 +934,14 @@ BeesScanModeExtent::SizeTier::find_next_extent()
 
 	// Low-level extent search debugging
 	shared_ptr<ostringstream> debug_oss;
+	const bool debug_oss_only_exceptions = true;
 #if 0
 	// Enable a _lot_ of debugging output
 	debug_oss = make_shared<ostringstream>();
 #endif
 	if (debug_oss) {
 		BtrfsIoctlSearchKey::s_debug_ostream = debug_oss;
+		tl_seeker_debug_str = debug_oss;
 	}
 
 	// Write out the stats no matter how we exit
@@ -948,27 +950,32 @@ BeesScanModeExtent::SizeTier::find_next_extent()
 		const auto search_calls = BtrfsIoctlSearchKey::s_calls - init_s_calls;
 		const auto search_loops = BtrfsIoctlSearchKey::s_loops - init_s_loops;
 		if (crawl_time.age() > 1) {
-			BEESLOGDEBUG(
-				"loop_count " << loop_count
-				<< " size_low_count " << size_low_count
-				<< " size_high_count " << size_high_count
-				<< " gen_low_count " << gen_low_count
-				<< " gen_high_count " << gen_high_count
-				<< " search_calls " << search_calls
-				<< " search_loops " << search_loops
-				<< " skips " << skip_count
-				<< " flops " << flop_count
-				<< " time " << crawl_time
-				<< " subvol " << m_subvol
-				<< " search/loop " << pretty(search_calls / loop_count)
-				<< " skip/loop " << (100 * skip_count / loop_count) << "%"
-				<< " flop/loop " << (100 * flop_count / loop_count) << "%"
-			);
+			if (loop_count) {
+				BEESLOGDEBUG(
+					"loop_count " << loop_count
+					<< " size_low_count " << size_low_count
+					<< " size_high_count " << size_high_count
+					<< " gen_low_count " << gen_low_count
+					<< " gen_high_count " << gen_high_count
+					<< " search_calls " << search_calls
+					<< " search_loops " << search_loops
+					<< " skips " << skip_count
+					<< " flops " << flop_count
+					<< " time " << crawl_time
+					<< " subvol " << m_subvol
+					<< " search/loop " << pretty(search_calls / loop_count)
+					<< " skip/loop " << (100 * skip_count / loop_count) << "%"
+					<< " flop/loop " << (100 * flop_count / loop_count) << "%"
+				);
+			}
 			if (debug_oss) {
-				BEESLOGDEBUG("debug oss trace:\n" << debug_oss->str());
+				if (!debug_oss_only_exceptions || exception_check()) {
+					BEESLOGDEBUG("debug oss trace:\n" << debug_oss->str());
+				}
 			}
 		}
 		BtrfsIoctlSearchKey::s_debug_ostream.reset();
+		tl_seeker_debug_str.reset();
 	});
 
 #define MNE_DEBUG(x) do { \
@@ -1001,7 +1008,9 @@ BeesScanModeExtent::SizeTier::find_next_extent()
 			// There is a lot of debug output.  Dump it if it gets too long
 			if (!debug_oss->str().empty()) {
 				if (crawl_time.age() > 1) {
-					BEESLOGDEBUG("debug oss trace (so far):\n" << debug_oss->str());
+					if (!debug_oss_only_exceptions) {
+						BEESLOGDEBUG("debug oss trace (so far):\n" << debug_oss->str());
+					}
 					debug_oss->str("");
 				}
 			}
@@ -1082,7 +1091,6 @@ BeesScanModeExtent::SizeTier::find_next_extent()
 			++size_low_count;
 
 			// Skip ahead over any below-min-size extents
-			BEESTRACE("min_size " << pretty(lower_size_bound) << " > scale_size " << pretty(m_fetcher.scale_size()));
 			const auto lsb_rounded = lower_size_bound & ~(m_fetcher.scale_size() - 1);
 			// Don't bother doing backward searches when skipping 128K or less.
 			// The search will cost more than reading 32 consecutive extent records.
@@ -1146,7 +1154,7 @@ BeesScanModeExtent::SizeTier::find_next_extent()
 		const auto hold_state = m_crawl->hold_state(this_state);
 		const auto sft = shared_from_this();
 		ostringstream oss;
-		oss << "map_" << to_hex(this_bytenr) << "_" << pretty(this_length);
+		oss << "map_" << hex << this_bytenr << dec << "_" << pretty(this_length);
 		Task create_map_task(oss.str(), [sft, this_bytenr, hold_state, this_length, find_next_task]() {
 			sft->create_extent_map(this_bytenr, hold_state, this_length, find_next_task);
 			BEESCOUNT(crawl_extent);
@@ -1321,23 +1329,25 @@ BeesScanModeExtent::next_transid()
 		}
 		const auto bytenr_offset = min(bi_last_bytenr, max(bytenr, bi.first_bytenr)) - bi.first_bytenr + bi.first_total;
 		const auto bytenr_norm = bytenr_offset / double(fs_size);
-		const auto time_so_far = now - min(now, this_state.m_started);
+		const auto eta_start = min(now, this_state.m_started);
+		const auto time_so_far = now - eta_start;
 		const string start_stamp = strf_localtime(this_state.m_started);
 		string eta_stamp = "-";
 		string eta_pretty = "-";
 		const auto &deferred_finished = deferred_map.at(subvol);
 		const bool finished = deferred_finished.second;
-		if (finished) {
-			// eta_stamp = "idle";
+		if (finished && m_roots->up_to_date(this_state)) {
+			eta_stamp = "idle";
 		} else if (time_so_far > 10 && bytenr_offset > 1024 * 1024 * 1024) {
 			const time_t eta_duration = time_so_far / bytenr_norm;
-			const time_t eta_time = eta_duration + now;
+			const time_t eta_time = eta_duration + eta_start;
+			const time_t eta_remain = eta_time - now;
 			eta_stamp = strf_localtime(eta_time);
-			eta_pretty = pretty_seconds(eta_duration);
+			eta_pretty = pretty_seconds(eta_remain);
 		}
 		const auto &mma = mes.m_map.at(subvol);
 		const auto mma_ratio = mes_sample_size_ok ? (mma.m_bytes / double(mes.m_total)) : 1.0;
-		const auto posn_text = Table::Text(finished ? "idle" : astringprintf("%06d", int(floor(bytenr_norm * 1000000))));
+		const auto posn_text = Table::Text(astringprintf("%06d", int(floor(bytenr_norm * 1000000))));
 		const auto size_text = Table::Text( mes_sample_size_ok ? pretty(fs_size * mma_ratio) : "-");
 		eta.insert_row(Table::endpos, vector<Table::Content> {
 			Table::Text(magic.m_max_size == numeric_limits<uint64_t>::max() ? "max" : pretty(magic.m_max_size)),
@@ -2013,7 +2023,7 @@ BeesRoots::open_root_nocache(uint64_t rootid)
 	BEESCOUNT(root_parent_open_try);
 	Fd parent_fd = open_root(parent_rootid);
 	if (!parent_fd) {
-		BEESLOGTRACE("no parent_fd");
+		BEESLOGDEBUG("no parent_fd for " << parent_rootid);
 		BEESCOUNT(root_parent_open_fail);
 		return Fd();
 	}
@@ -2036,7 +2046,7 @@ BeesRoots::open_root_nocache(uint64_t rootid)
 		BEESTRACE("dirid " << dirid << " path " << ino.m_paths.at(0));
 		parent_fd = bees_openat(parent_fd, ino.m_paths.at(0).c_str(), FLAGS_OPEN_DIR);
 		if (!parent_fd) {
-			BEESLOGTRACE("no parent_fd from dirid");
+			BEESLOGDEBUG("no parent_fd from dirid " << dirid << " in parent_rootid " << parent_rootid);
 			BEESCOUNT(root_parent_path_open_fail);
 			return Fd();
 		}
@@ -2044,7 +2054,7 @@ BeesRoots::open_root_nocache(uint64_t rootid)
 	BEESTRACE("openat(" << name_fd(parent_fd) << ", " << name << ")");
 	Fd rv = bees_openat(parent_fd, name.c_str(), FLAGS_OPEN_DIR);
 	if (!rv) {
-		BEESLOGTRACE("open failed for name " << name << ": " << strerror(errno));
+		BEESLOGDEBUG("open failed for name " << name << " in parent_fd " << name_fd(parent_fd) << ": " << strerror(errno));
 		BEESCOUNT(root_open_fail);
 		return rv;
 	}
@@ -2301,16 +2311,20 @@ BeesCrawl::BeesCrawl(shared_ptr<BeesContext> ctx, BeesCrawlState initial_state)
 	}
 }
 
+bool
+BeesRoots::up_to_date(const BeesCrawlState &bcs)
+{
+	// If we are already at transid_max then we are up to date
+	return bcs.m_max_transid >= transid_max();
+}
+
 bool
 BeesCrawl::restart_crawl_unlocked()
 {
 	const auto roots = m_ctx->roots();
-	const auto next_transid = roots->transid_max();
-
 	auto crawl_state = get_state_end();
 
-	// If we are already at transid_max then we are still finished
-	m_finished = crawl_state.m_max_transid >= next_transid;
+	m_finished = roots->up_to_date(crawl_state);
 
 	if (m_finished) {
 		m_deferred = true;
@@ -2321,7 +2335,7 @@ BeesCrawl::restart_crawl_unlocked()
 
 		// Start new crawl
 		crawl_state.m_min_transid = crawl_state.m_max_transid;
-		crawl_state.m_max_transid = next_transid;
+		crawl_state.m_max_transid = roots->transid_max();
 		crawl_state.m_objectid = 0;
 		crawl_state.m_offset = 0;
 		crawl_state.m_started = current_time;

src/bees-trace.cc

@@ -8,38 +8,32 @@ thread_local BeesTracer *BeesTracer::tl_next_tracer = nullptr;
 thread_local bool BeesTracer::tl_first = true;
 thread_local bool BeesTracer::tl_silent = false;
 
+bool
+exception_check()
+{
 #if __cplusplus >= 201703
-static
-bool
-exception_check()
-{
 	return uncaught_exceptions();
-}
 #else
-static
-bool
-exception_check()
-{
 	return uncaught_exception();
-}
 #endif
+}
 
 BeesTracer::~BeesTracer()
 {
 	if (!tl_silent && exception_check()) {
 		if (tl_first) {
-			BEESLOGNOTICE("--- BEGIN TRACE --- exception ---");
+			BEESLOG(BEES_TRACE_LEVEL, "TRACE: --- BEGIN TRACE --- exception ---");
 			tl_first = false;
 		}
 		try {
 			m_func();
 		} catch (exception &e) {
-			BEESLOGNOTICE("Nested exception: " << e.what());
+			BEESLOG(BEES_TRACE_LEVEL, "TRACE: Nested exception: " << e.what());
 		} catch (...) {
-			BEESLOGNOTICE("Nested exception ...");
+			BEESLOG(BEES_TRACE_LEVEL, "TRACE: Nested exception ...");
 		}
 		if (!m_next_tracer) {
-			BEESLOGNOTICE("---  END  TRACE --- exception ---");
+			BEESLOG(BEES_TRACE_LEVEL, "TRACE: ---  END  TRACE --- exception ---");
 		}
 	}
 	tl_next_tracer = m_next_tracer;
@@ -49,7 +43,7 @@ BeesTracer::~BeesTracer()
 	}
 }
 
-BeesTracer::BeesTracer(function<void()> f, bool silent) :
+BeesTracer::BeesTracer(const function<void()> &f, bool silent) :
 	m_func(f)
 {
 	m_next_tracer = tl_next_tracer;
@@ -61,12 +55,12 @@ void
 BeesTracer::trace_now()
 {
 	BeesTracer *tp = tl_next_tracer;
-	BEESLOGNOTICE("--- BEGIN TRACE ---");
+	BEESLOG(BEES_TRACE_LEVEL, "TRACE: --- BEGIN TRACE ---");
 	while (tp) {
 		tp->m_func();
 		tp = tp->m_next_tracer;
 	}
-	BEESLOGNOTICE("---  END  TRACE ---");
+	BEESLOG(BEES_TRACE_LEVEL, "TRACE: ---  END  TRACE ---");
 }
 
 bool

src/bees-types.cc

@@ -572,7 +572,7 @@ BeesRangePair::grow(shared_ptr<BeesContext> ctx, bool constrained)
 	}
 
 	if (first.overlaps(second)) {
-		BEESLOGTRACE("after grow, first " << first << "\n\toverlaps " << second);
+		BEESLOGDEBUG("after grow, first " << first << "\n\toverlaps " << second);
 		BEESCOUNT(bug_grow_pair_overlaps);
 	}
 
@@ -674,7 +674,7 @@ BeesAddress::magic_check(uint64_t flags)
 	static const unsigned recognized_flags = compressed_flags | delalloc_flags | ignore_flags | unusable_flags;
 
 	if (flags & ~recognized_flags) {
-		BEESLOGTRACE("Unrecognized flags in " << fiemap_extent_flags_ntoa(flags));
+		BEESLOGNOTICE("Unrecognized flags in " << fiemap_extent_flags_ntoa(flags));
 		m_addr = UNUSABLE;
 		// maybe we throw here?
 		BEESCOUNT(addr_unrecognized);

src/bees.cc

@@ -4,6 +4,7 @@
 #include "crucible/process.h"
 #include "crucible/string.h"
 #include "crucible/task.h"
+#include "crucible/uname.h"
 
 #include <cctype>
 #include <cmath>
@@ -11,17 +12,19 @@
 
 #include <iostream>
 #include <memory>
+#include <regex>
 #include <sstream>
 
 // PRIx64
 #include <inttypes.h>
 
-#include <sched.h>
-#include <sys/fanotify.h>
-
 #include <linux/fs.h>
 #include <sys/ioctl.h>
 
+// statfs
+#include <linux/magic.h>
+#include <sys/statfs.h>
+
 // setrlimit
 #include <sys/time.h>
 #include <sys/resource.h>
@@ -391,6 +394,73 @@ BeesStringFile::read()
 	return read_string(fd, st.st_size);
 }
 
+static
+void
+bees_fsync(int const fd)
+{
+
+	// Note that when btrfs renames a temporary over an existing file,
+	// it flushes the temporary, so we get the right behavior if we
+	// just do nothing here (except when the file is first created;
+	// however, in that case the result is the same as if the file
+	// did not exist, was empty, or was filled with garbage).
+	//
+	// Kernel versions prior to 5.16 had bugs which would put ghost
+	// dirents in $BEESHOME if there was a crash when we called
+	// fsync() here.
+	//
+	// Some other filesystems will throw our data away if we don't
+	// call fsync, so we do need to call fsync() on those filesystems.
+	//
+	// Newer btrfs kernel versions rely on fsync() to report
+	// unrecoverable write errors.	If we don't check the fsync()
+	// result, we'll lose the data when we rename().  Kernel 6.2 added
+	// a number of new root causes for the class of "unrecoverable
+	// write errors" so we need to check this now.
+
+	BEESNOTE("checking filesystem type for " << name_fd(fd));
+	// LSB deprecated statfs without providing a replacement that
+	// can fill in the f_type field.
+	struct statfs stf = { 0 };
+	DIE_IF_NON_ZERO(fstatfs(fd, &stf));
+	if (stf.f_type != BTRFS_SUPER_MAGIC) {
+		BEESLOGONCE("Using fsync on non-btrfs filesystem type " << to_hex(stf.f_type));
+		BEESNOTE("fsync non-btrfs " << name_fd(fd));
+		DIE_IF_NON_ZERO(fsync(fd));
+		return;
+	}
+
+	static bool did_uname = false;
+	static bool do_fsync = false;
+
+	if (!did_uname) {
+		Uname uname;
+		const string version(uname.release);
+		static const regex version_re(R"/(^(\d+)\.(\d+)\.)/", regex::optimize | regex::ECMAScript);
+		smatch m;
+		// Last known bug in the fsync-rename use case was fixed in kernel 5.16
+		static const auto min_major = 5, min_minor = 16;
+		if (regex_search(version, m, version_re)) {
+			const auto major = stoul(m[1]);
+			const auto minor = stoul(m[2]);
+			if (tie(major, minor) > tie(min_major, min_minor)) {
+				BEESLOGONCE("Using fsync on btrfs because kernel version is " << major << "." << minor);
+				do_fsync = true;
+			} else {
+				BEESLOGONCE("Not using fsync on btrfs because kernel version is " << major << "." << minor);
+			}
+		} else {
+			BEESLOGONCE("Not using fsync on btrfs because can't parse kernel version '" << version << "'");
+		}
+		did_uname = true;
+	}
+
+	if (do_fsync) {
+		BEESNOTE("fsync btrfs " << name_fd(fd));
+		DIE_IF_NON_ZERO(fsync(fd));
+	}
+}
+
 void
 BeesStringFile::write(string contents)
 {
@@ -406,19 +476,8 @@ BeesStringFile::write(string contents)
 		Fd ofd = openat_or_die(m_dir_fd, tmpname, FLAGS_CREATE_FILE, S_IRUSR | S_IWUSR);
 		BEESNOTE("writing " << tmpname << " in " << name_fd(m_dir_fd));
 		write_or_die(ofd, contents);
-#if 0
-		// This triggers too many btrfs bugs.  I wish I was kidding.
-		// Forget snapshots, balance, compression, and dedupe:
-		// the system call you have to fear on btrfs is fsync().
-		// Also note that when bees renames a temporary over an
-		// existing file, it flushes the temporary, so we get
-		// the right behavior if we just do nothing here
-		// (except when the file is first created; however,
-		// in that case the result is the same as if the file
-		// did not exist, was empty, or was filled with garbage).
 		BEESNOTE("fsyncing " << tmpname << " in " << name_fd(m_dir_fd));
-		DIE_IF_NON_ZERO(fsync(ofd));
-#endif
+		bees_fsync(ofd);
 	}
 	BEESNOTE("renaming " << tmpname << " to " << m_name << " in FD " << name_fd(m_dir_fd));
 	BEESTRACE("renaming " << tmpname << " to " << m_name << " in FD " << name_fd(m_dir_fd));
@@ -443,6 +502,19 @@ BeesTempFile::resize(off_t offset)
 	// Count time spent here
 	BEESCOUNTADD(tmp_resize_ms, resize_timer.age() * 1000);
 
+	// Modify flags - every time
+	// - btrfs will keep trying to set FS_NOCOMP_FL behind us when compression heuristics identify
+	//   the data as compressible, but it fails to compress
+	// - clear FS_NOCOW_FL because we can only dedupe between files with the same FS_NOCOW_FL state,
+	//   and we don't open FS_NOCOW_FL files for dedupe.
+	BEESTRACE("Getting FS_COMPR_FL and FS_NOCOMP_FL on m_fd " << name_fd(m_fd));
+	int flags = ioctl_iflags_get(m_fd);
+	flags |= FS_COMPR_FL;
+	flags &= ~(FS_NOCOMP_FL | FS_NOCOW_FL);
+	BEESTRACE("Setting FS_COMPR_FL and clearing FS_NOCOMP_FL | FS_NOCOW_FL on m_fd " << name_fd(m_fd) << " flags " << to_hex(flags));
+	ioctl_iflags_set(m_fd, flags);
+
+	// That may have queued some delayed ref deletes, so throttle them
 	bees_throttle(resize_timer.age(), "tmpfile_resize");
 }
 
@@ -484,13 +556,6 @@ BeesTempFile::BeesTempFile(shared_ptr<BeesContext> ctx) :
 	// Add this file to open_root_ino lookup table
 	m_roots->insert_tmpfile(m_fd);
 
-	// Set compression attribute
-	BEESTRACE("Getting FS_COMPR_FL on m_fd " << name_fd(m_fd));
-	int flags = ioctl_iflags_get(m_fd);
-	flags |= FS_COMPR_FL;
-	BEESTRACE("Setting FS_COMPR_FL on m_fd " << name_fd(m_fd) << " flags " << to_hex(flags));
-	ioctl_iflags_set(m_fd, flags);
-
 	// Count time spent here
 	BEESCOUNTADD(tmp_create_ms, create_timer.age() * 1000);
 
@@ -682,7 +747,7 @@ bees_main(int argc, char *argv[])
 			BEESLOGDEBUG("exception (ignored): " << s);
 			BEESCOUNT(exception_caught_silent);
 		} else {
-			BEESLOGNOTICE("\n\n*** EXCEPTION ***\n\t" << s << "\n***\n");
+			BEESLOG(BEES_TRACE_LEVEL, "TRACE: EXCEPTION: " << s);
 			BEESCOUNT(exception_caught);
 		}
 	});

src/bees.h

@@ -122,9 +122,9 @@ const int FLAGS_OPEN_FANOTIFY = O_RDWR | O_NOATIME | O_CLOEXEC | O_LARGEFILE;
 // macros ----------------------------------------
 
 #define BEESLOG(lv,x)   do { if (lv < bees_log_level) { Chatter __chatter(lv, BeesNote::get_name()); __chatter << x; } } while (0)
-#define BEESLOGTRACE(x) do { BEESLOG(LOG_DEBUG, x); BeesTracer::trace_now(); } while (0)
 
-#define BEESTRACE(x)   BeesTracer  SRSLY_WTF_C(beesTracer_,  __LINE__) ([&]()                 { BEESLOG(LOG_ERR, x << " at " << __FILE__ << ":" << __LINE__);   })
+#define BEES_TRACE_LEVEL LOG_DEBUG
+#define BEESTRACE(x)   BeesTracer  SRSLY_WTF_C(beesTracer_,  __LINE__) ([&]()                 { BEESLOG(BEES_TRACE_LEVEL, "TRACE: " << x << " at " << __FILE__ << ":" << __LINE__);   })
 #define BEESTOOLONG(x) BeesTooLong SRSLY_WTF_C(beesTooLong_, __LINE__) ([&](ostream &_btl_os) { _btl_os << x; })
 #define BEESNOTE(x)    BeesNote    SRSLY_WTF_C(beesNote_,    __LINE__) ([&](ostream &_btl_os) { _btl_os << x; })
 
@@ -134,6 +134,14 @@ const int FLAGS_OPEN_FANOTIFY = O_RDWR | O_NOATIME | O_CLOEXEC | O_LARGEFILE;
 #define BEESLOGINFO(x)   BEESLOG(LOG_INFO, x)
 #define BEESLOGDEBUG(x)  BEESLOG(LOG_DEBUG, x)
 
+#define BEESLOGONCE(__x) do { \
+        static bool already_logged = false; \
+        if (!already_logged) { \
+                already_logged = true; \
+                BEESLOGNOTICE(__x); \
+        } \
+} while (false)
+
 #define BEESCOUNT(stat) do { \
 	BeesStats::s_global.add_count(#stat); \
 } while (0)
@@ -185,7 +193,7 @@ class BeesTracer {
 	thread_local static bool tl_silent;
 	thread_local static bool tl_first;
 public:
-	BeesTracer(function<void()> f, bool silent = false);
+	BeesTracer(const function<void()> &f, bool silent = false);
 	~BeesTracer();
 	static void trace_now();
 	static bool get_silent();
@@ -580,8 +588,8 @@ class BeesRoots : public enable_shared_from_this<BeesRoots> {
 	void current_state_set(const BeesCrawlState &bcs);
 	bool crawl_batch(shared_ptr<BeesCrawl> crawl);
 	void clear_caches();
-
 	shared_ptr<BeesCrawl> insert_root(const BeesCrawlState &bcs);
+	bool up_to_date(const BeesCrawlState &bcs);
 
 friend class BeesCrawl;
 friend class BeesFdCache;
@@ -893,5 +901,6 @@ void bees_readahead_pair(int fd, off_t offset, size_t size, int fd2, off_t offse
 void bees_unreadahead(int fd, off_t offset, size_t size);
 void bees_throttle(double time_used, const char *context);
 string format_time(time_t t);
+bool exception_check();
 
 #endif

test/seeker.cc

@@ -19,7 +19,9 @@ seeker_finder(const vector<uint64_t> &vec, uint64_t lower, uint64_t upper)
 	if (ub != s.end()) ++ub;
 	if (ub != s.end()) ++ub;
 	for (; ub != s.end(); ++ub) {
-		if (*ub > upper) break;
+		if (*ub > upper) {
+			break;
+		}
 	}
 	return set<uint64_t>(lb, ub);
 }
@@ -28,7 +30,7 @@ static bool test_fails = false;
 
 static
 void
-seeker_test(const vector<uint64_t> &vec, uint64_t const target)
+seeker_test(const vector<uint64_t> &vec, uint64_t const target, bool const always_out = false)
 {
 	cerr << "Find " << target << " in {";
 	for (auto i : vec) {
@@ -36,11 +38,13 @@ seeker_test(const vector<uint64_t> &vec, uint64_t const target)
 	}
 	cerr << " } = ";
 	size_t loops = 0;
+	tl_seeker_debug_str = make_shared<ostringstream>();
+	bool local_test_fails = false;
 	bool excepted = catch_all([&]() {
-		auto found = seek_backward(target, [&](uint64_t lower, uint64_t upper) {
+		const auto found = seek_backward(target, [&](uint64_t lower, uint64_t upper) {
 			++loops;
 			return seeker_finder(vec, lower, upper);
-		});
+		}, uint64_t(32));
 		cerr << found;
 		uint64_t my_found = 0;
 		for (auto i : vec) {
@@ -52,13 +56,15 @@ seeker_test(const vector<uint64_t> &vec, uint64_t const target)
 			cerr << " (correct)";
 		} else {
 			cerr << " (INCORRECT - right answer is " << my_found << ")";
-			test_fails = true;
+			local_test_fails = true;
 		}
 	});
 	cerr << " (" << loops << " loops)" << endl;
-	if (excepted) {
-		test_fails = true;
+	if (excepted || local_test_fails || always_out) {
+		cerr << dynamic_pointer_cast<ostringstream>(tl_seeker_debug_str)->str();
 	}
+	test_fails = test_fails || local_test_fails;
+	tl_seeker_debug_str.reset();
 }
 
 static
@@ -89,6 +95,39 @@ test_seeker()
 	seeker_test(vector<uint64_t> { 0, numeric_limits<uint64_t>::max() }, numeric_limits<uint64_t>::max());
 	seeker_test(vector<uint64_t> { 0, numeric_limits<uint64_t>::max() }, numeric_limits<uint64_t>::max() - 1);
 	seeker_test(vector<uint64_t> { 0, numeric_limits<uint64_t>::max() - 1 }, numeric_limits<uint64_t>::max());
+
+	seeker_test(vector<uint64_t> { 0, 1, 2, 4, 8 }, 0);
+	seeker_test(vector<uint64_t> { 0, 1, 2, 4, 8 }, 1);
+	seeker_test(vector<uint64_t> { 0, 1, 2, 4, 8 }, 2);
+	seeker_test(vector<uint64_t> { 0, 1, 2, 4, 8 }, 3);
+	seeker_test(vector<uint64_t> { 0, 1, 2, 4, 8 }, 4);
+	seeker_test(vector<uint64_t> { 0, 1, 2, 4, 8 }, 5);
+	seeker_test(vector<uint64_t> { 0, 1, 2, 4, 8 }, 6);
+	seeker_test(vector<uint64_t> { 0, 1, 2, 4, 8 }, 7);
+	seeker_test(vector<uint64_t> { 0, 1, 2, 4, 8 }, 8);
+	seeker_test(vector<uint64_t> { 0, 1, 2, 4, 8 }, 9);
+	seeker_test(vector<uint64_t> { 0, 1, 2, 4, 8 }, numeric_limits<uint64_t>::max() );
+	seeker_test(vector<uint64_t> { 0, 1, 2, 4, 8 }, numeric_limits<uint64_t>::max() - 1 );
+	seeker_test(vector<uint64_t> { 0, 1, 2, 4, 8 }, numeric_limits<uint64_t>::max() - 2 );
+	seeker_test(vector<uint64_t> { 0, 1, 2, 4, 8 }, numeric_limits<uint64_t>::max() - 3 );
+	seeker_test(vector<uint64_t> { 0, 1, 2, 4, 8 }, numeric_limits<uint64_t>::max() - 4 );
+	seeker_test(vector<uint64_t> { 0, 1, 2, 4, 8 }, numeric_limits<uint64_t>::max() - 5 );
+	seeker_test(vector<uint64_t> { 0, 1, 2, 4, 8 }, numeric_limits<uint64_t>::max() - 6 );
+	seeker_test(vector<uint64_t> { 0, 1, 2, 4, 8 }, numeric_limits<uint64_t>::max() - 7 );
+	seeker_test(vector<uint64_t> { 0, 1, 2, 4, 8 }, numeric_limits<uint64_t>::max() - 8 );
+
+	// Pulled from a bees debug log
+	seeker_test(vector<uint64_t> {
+		6821962845,
+		6821962848,
+		6821963411,
+		6821963422,
+		6821963536,
+		6821963539,
+		6821963835, // <- appeared during the search, causing an exception
+		6821963841,
+		6822575316,
+	}, 6821971036, true);
 }