Added Redwood pager and BTree overview statistics to trace events logged on creation and recovery. Changed getStorageBytes() to treat internal space used by free list queues as reusable.

fdbclient/FDBTypes.h

@@ -864,6 +864,14 @@ struct StorageBytes {
 		              used / 1e6,
 		              temp / 1e6);
 	}
+
+	void toTraceEvent(TraceEvent& e) const {
+		e.detail("StorageBytesUsed", used)
+		    .detail("StorageBytesTemp", temp)
+		    .detail("StorageBytesTotal", total)
+		    .detail("StorageBytesFree", free)
+		    .detail("StorageBytesAvailable", available);
+	}
 };
 struct LogMessageVersion {
 	// Each message pushed into the log system has a unique, totally ordered LogMessageVersion

fdbserver/VersionedBTree.actor.cpp

@@ -18,6 +18,7 @@
  * limitations under the License.
  */
 
+#include "fdbclient/FDBTypes.h"
 #include "fdbserver/Knobs.h"
 #include "flow/IRandom.h"
 #include "flow/Knobs.h"
@@ -1440,6 +1441,12 @@ public:
 
 	// For debugging
 	std::string name;
+
+	void toTraceEvent(TraceEvent& e, const char* prefix) const {
+		e.detail(format("%sRecords", prefix), numEntries);
+		e.detail(format("%sPages", prefix), numPages);
+		e.detail(format("%sRecordsPerPage", prefix), numPages > 0 ? (double)numEntries / numPages : 0);
+	}
 };
 
 int nextPowerOf2(uint32_t x) {
@@ -2283,16 +2290,11 @@ public:
 			self->remapQueue.resetHeadReader();
 
 			self->remapCleanupFuture = remapCleanup(self);
-			TraceEvent(SevInfo, "RedwoodRecovered")
-			    .detail("FileName", self->filename.c_str())
-			    .detail("CommittedVersion", self->pHeader->committedVersion)
-			    .detail("LogicalPageSize", self->logicalPageSize)
-			    .detail("PhysicalPageSize", self->physicalPageSize)
-			    .detail("RemapEntries", self->remapQueue.numEntries);
 		} else {
 			// Note: If the file contains less than 2 pages but more than 0 bytes then the pager was never successfully
 			// committed. A new pager will be created in its place.
 			// TODO:  Is the right behavior?
+			exists = false;
 
 			debug_printf("DWALPager(%s) creating new pager\n", self->filename.c_str());
 
@@ -2352,6 +2354,26 @@ public:
 			wait(self->commit());
 		}
 
+		if (!self->memoryOnly) {
+			wait(store(fileSize, self->pageFile->size()));
+		}
+
+		TraceEvent e(SevInfo, "RedwoodRecoveredPager");
+		e.detail("FileName", self->filename.c_str());
+		e.detail("LogicalFileSize", self->pHeader->pageCount * self->physicalPageSize);
+		e.detail("PhysicalFileSize", fileSize);
+		e.detail("OpenedExisting", exists);
+		e.detail("CommittedVersion", self->pHeader->committedVersion);
+		e.detail("LogicalPageSize", self->logicalPageSize);
+		e.detail("PhysicalPageSize", self->physicalPageSize);
+
+		self->remapQueue.toTraceEvent(e, "RemapQueue");
+		self->delayedFreeList.toTraceEvent(e, "FreeQueue");
+		self->freeList.toTraceEvent(e, "DelayedFreeQueue");
+		self->extentUsedList.toTraceEvent(e, "UsedExtentQueue");
+		self->extentFreeList.toTraceEvent(e, "FreeExtentQueue");
+		self->getStorageBytes().toTraceEvent(e);
+
 		debug_printf("DWALPager(%s) recovered.  committedVersion=%" PRId64 " logicalPageSize=%d physicalPageSize=%d\n",
 		             self->filename.c_str(),
 		             self->pHeader->committedVersion,
@@ -3369,7 +3391,6 @@ public:
 	Future<Void> onClosed() override { return closedPromise.getFuture(); }
 
 	StorageBytes getStorageBytes() const override {
-		ASSERT(recoverFuture.isReady());
 		int64_t free;
 		int64_t total;
 		if (memoryOnly) {
@@ -3383,7 +3404,15 @@ public:
 		// It is not exactly known how many pages on the delayed free list are usable as of right now.  It could be
 		// known, if each commit delayed entries that were freeable were shuffled from the delayed free queue to the
 		// free queue, but this doesn't seem necessary.
-		int64_t reusable = (freeList.numEntries + delayedFreeList.numEntries) * physicalPageSize;
+
+		// Amount of space taken up by all of the items in the free lists
+		int64_t reusablePageSpace = (freeList.numEntries + delayedFreeList.numEntries) * physicalPageSize;
+		// Amount of space taken up by the free list queues themselves, as if we were to pop and use
+		// items on the free lists the space the items are stored in would also become usable
+		int64_t reusableQueueSpace = (freeList.numPages + delayedFreeList.numPages) * physicalPageSize;
+		int64_t reusable = reusablePageSpace + reusableQueueSpace;
+
+		// Space currently in used by old page versions have have not yet been freed due to the remap cleanup window.
 		int64_t temp = remapQueue.numEntries * physicalPageSize;
 
 		return StorageBytes(free, total, pagerSize - reusable, free + reusable, temp);
@@ -4654,6 +4683,12 @@ public:
 
 		debug_printf("Recovered btree at version %" PRId64 ": %s\n", latest, self->m_pHeader->toString().c_str());
 
+		TraceEvent e(SevInfo, "RedwoodRecoveredBTree");
+		e.detail("FileName", self->m_name);
+		e.detail("OpenedExisting", meta.size() != 0);
+		e.detail("LatestVersion", latest);
+		self->m_lazyClearQueue.toTraceEvent(e, "LazyClearQueue");
+
 		self->m_lastCommittedVersion = latest;
 		self->m_lazyClearActor = incrementalLazyClear(self);
 		return Void();
@@ -4695,8 +4730,6 @@ public:
 	}
 
 	ACTOR static Future<Void> clearAllAndCheckSanity_impl(VersionedBTree* self) {
-		ASSERT(g_network->isSimulated());
-
 		debug_printf("Clearing tree.\n");
 		self->setWriteVersion(self->getLatestVersion() + 1);
 		self->clear(KeyRangeRef(dbBegin.key, dbEnd.key));
@@ -9464,6 +9497,7 @@ TEST_CASE(":/redwood/performance/set") {
 	state int scanPrefetchBytes = params.getInt("scanPrefetchBytes").orDefault(0);
 	state bool pagerMemoryOnly = params.getInt("pagerMemoryOnly").orDefault(0);
 	state bool traceMetrics = params.getInt("traceMetrics").orDefault(0);
+	state bool destructiveSanityCheck = params.getInt("destructiveSanityCheck").orDefault(0);
 
 	printf("pagerMemoryOnly: %d\n", pagerMemoryOnly);
 	printf("pageSize: %d\n", pageSize);
@@ -9490,6 +9524,7 @@ TEST_CASE(":/redwood/performance/set") {
 	printf("fileName: %s\n", fileName.c_str());
 	printf("openExisting: %d\n", openExisting);
 	printf("insertRecords: %d\n", insertRecords);
+	printf("destructiveSanityCheck: %d\n", destructiveSanityCheck);
 
 	// If using stdout for metrics, prevent trace event metrics logger from starting
 	if (!traceMetrics) {
@@ -9625,6 +9660,10 @@ TEST_CASE(":/redwood/performance/set") {
 		}
 	}
 
+	if (destructiveSanityCheck) {
+		wait(btree->clearAllAndCheckSanity());
+	}
+
 	Future<Void> closedFuture = btree->onClosed();
 	btree->close();
 	wait(closedFuture);

fdbserver/workloads/MutationLogReaderCorrectness.actor.cpp

@@ -59,7 +59,7 @@ struct MutationLogReaderCorrectnessWorkload : TestWorkload {
 		    0, std::numeric_limits<int32_t>::max()); // intentionally not max of int64
 		records = deterministicRandom()->randomInt(0, 1e6);
 		versionRange = deterministicRandom()->randomInt64(records, std::numeric_limits<Version>::max());
-		versionIncrement = versionRange / records;
+		versionIncrement = versionRange / (records + 1);
 
 		// The version immediately after the last actual record version
 		endVersion = recordVersion(records - 1) + 1;