Add contrib/debug_determinism (#6389)

* Add contrib/debug_determinism

Add an instrumentation-based technique for debugging unseen mismatches. Also guard a few existing sources of nondeterminism that don't affect unseen with the DEBUG_DETERMINISM macro.

Also change the simulated run loop to not run as the only task inside the real run loop, since that was a source of nondeterminism.

Also fix nondeterminism from calling timer_int

* Add StorageMetadataType::currentTime

Basically a deterministic-in-simulation version of timer_int that we can
use instead of timer_int for StorageMetadataType::createdTime

contrib/CMakeLists.txt

@@ -1,5 +1,6 @@
 add_subdirectory(fmt-8.0.1)
 if(NOT WIN32)
+  add_subdirectory(debug_determinism)
   add_subdirectory(monitoring)
   add_subdirectory(TraceLogHelper)
   add_subdirectory(TestHarness)

contrib/debug_determinism/CMakeLists.txt

@@ -0,0 +1,5 @@
+add_library(debug_determinism STATIC debug_determinism.cpp)
+
+# So that we can link to libfdb_c.so. Not strictly necessary but convenient for use with our
+# TRACE_PC_GUARD_INSTRUMENTATION_LIB cmake option
+target_compile_options(debug_determinism PRIVATE -fPIC)

contrib/debug_determinism/README.md

@@ -0,0 +1,45 @@
+Utilities for debugging unseed mismatches for foundationdb simulation tests.
+
+99/100 times the source of the nondeterminism is use of uninitialized memory and
+what you want to do is build with `-DUSE_VALGRIND=ON` and run simulations under
+valgrind.
+
+Common sources of nondeterminism and specialized tools to find them.
+1. Use of uninitialized memory (use valgrind!)
+1. Memory errors (use valgrind and/or asan)
+1. Undefined behavior (use ubsan. You can also try _GLIBCXX_DEBUG)
+
+If it's not any of these then now it's time to try this technique. Look for
+
+1. Call to some kind of "get current time" function that's not in `INetwork`
+1. Depending on the relative ordering of allocated memory. E.g. Using heap-allocated pointers as keys in a `std::map`.
+1. Inspecting something about the current state of the system (e.g. free disk space)
+1. Depending on iteration order of an unordered map
+
+# Quickstart
+
+Set these cmake flags
+
+```
+-DTRACE_PC_GUARD_INSTRUMENTATION_LIB=$BUILDDIR/lib/libdebug_determinism.a
+```
+
+and change `#define DEBUG_DETERMINISM 0` to `#define DEBUG_DETERMINISM 1` in
+flow/Platform.h. This disables several known sources of nondeterminism that
+don't affect unseeds.
+
+For reasons I don't fully understand, it appears that sqlite exhibits some
+nondeterminism if you don't add `#define SQLITE_OMIT_LOOKASIDE` to the top of
+fdbserver/sqlite/sqlite3.amalgamation.c, so you probably want to do that too.
+
+Now when you run an fdbserver simulation, it will write a file `out.bin` in the
+current directory which contains the sequence of edges in the control flow graph
+that were encountered during the simulation. If you rename `out.bin` to `in.bin`
+and then re-run, the simulation will validate that the sequence of edges is the
+same as the last run. If it's not, then the simulation will enter an infinite
+loop at the first difference and print a message. Then you probably want to
+attach gdb to the process and investigate from there.
+
+You'll need to make sure you delete the `simfdb` folder before each run, because
+otherwise you'll take a different codepath for deleting the `simfdb` folder at
+the beginning of simulation.

contrib/debug_determinism/debug_determinism.cpp

@@ -0,0 +1,52 @@
+#include <stdint.h>
+#include <stdio.h>
+
+namespace {
+FILE* out = nullptr;
+FILE* in = nullptr;
+void loop_forever() {
+	// Try to convince the optimizer not to optimize away this loop
+	static volatile uint64_t x = 0;
+	for (;;) {
+		++x;
+	}
+}
+} // namespace
+
+// This callback is inserted by the compiler as a module constructor
+// into every DSO. 'start' and 'stop' correspond to the
+// beginning and end of the section with the guards for the entire
+// binary (executable or DSO). The callback will be called at least
+// once per DSO and may be called multiple times with the same parameters.
+extern "C" void __sanitizer_cov_trace_pc_guard_init(uint32_t* start, uint32_t* stop) {
+	in = fopen("in.bin", "r");
+	out = fopen("out.bin", "w");
+	static uint64_t N; // Counter for the guards.
+	if (start == stop || *start)
+		return; // Initialize only once.
+	for (uint32_t* x = start; x < stop; x++) {
+		*x = ++N; // Guards should start from 1.
+	}
+}
+
+// This callback is inserted by the compiler on every edge in the
+// control flow (some optimizations apply).
+// Typically, the compiler will emit the code like this:
+//    if(*guard)
+//      __sanitizer_cov_trace_pc_guard(guard);
+// But for large functions it will emit a simple call:
+//    __sanitizer_cov_trace_pc_guard(guard);
+extern "C" void __sanitizer_cov_trace_pc_guard(uint32_t* guard) {
+	if (!guard) {
+		return;
+	}
+	fwrite(guard, 1, sizeof(*guard), out);
+	if (in) {
+		uint32_t theirs;
+		fread(&theirs, 1, sizeof(theirs), in);
+		if (*guard != theirs) {
+			printf("Non-determinism detected\n");
+			loop_forever();
+		}
+	}
+}

fdbclient/FDBTypes.h

@@ -1204,10 +1204,12 @@ struct ReadBlobGranuleContext {
 struct StorageMetadataType {
 	constexpr static FileIdentifier file_identifier = 732123;
 	// when the SS is initialized
-	uint64_t createdTime; // comes from Platform::timer_int()
+	uint64_t createdTime; // comes from currentTime()
 	StorageMetadataType() : createdTime(0) {}
 	StorageMetadataType(uint64_t t) : createdTime(t) {}
 
+	static uint64_t currentTime() { return g_network->timer() * 1e9; }
+
 	// To change this serialization, ProtocolVersion::StorageMetadata must be updated, and downgrades need
 	// to be considered
 	template <class Ar>

fdbrpc/sim2.actor.cpp

@@ -1123,11 +1123,9 @@ public:
 		}
 	}
 
-	ACTOR static Future<Void> runLoop(Sim2* self) {
-		state ISimulator::ProcessInfo* callingMachine = self->currentProcess;
+	static void runLoop(Sim2* self) {
+		ISimulator::ProcessInfo* callingMachine = self->currentProcess;
 		while (!self->isStopped) {
-			wait(self->net2->yield(TaskPriority::DefaultYield));
-
 			self->mutex.enter();
 			if (self->tasks.size() == 0) {
 				self->mutex.leave();
@@ -1144,18 +1142,13 @@ public:
 			self->yielded = false;
 		}
 		self->currentProcess = callingMachine;
-		self->net2->stop();
 		for (auto& fn : self->stopCallbacks) {
 			fn();
 		}
-		return Void();
 	}
 
 	// Implement ISimulator interface
-	void run() override {
-		Future<Void> loopFuture = runLoop(this);
-		net2->run();
-	}
+	void run() override { runLoop(this); }
 	ProcessInfo* newProcess(const char* name,
 	                        IPAddress ip,
 	                        uint16_t port,

fdbserver/DDTeamCollection.actor.cpp

@@ -2857,7 +2857,7 @@ public:
 		state KeyBackedObjectMap<UID, StorageMetadataType, decltype(IncludeVersion())> metadataMap(
 		    serverMetadataKeys.begin, IncludeVersion());
 		state Reference<ReadYourWritesTransaction> tr = makeReference<ReadYourWritesTransaction>(self->cx);
-		state StorageMetadataType data(timer_int());
+		state StorageMetadataType data(StorageMetadataType::currentTime());
 		// printf("------ read metadata %s\n", server->getId().toString().c_str());
 		// read storage metadata
 		loop {

fdbserver/MoveKeys.actor.cpp

@@ -1151,7 +1151,7 @@ ACTOR Future<std::pair<Version, Tag>> addStorageServer(Database cx, StorageServe
 				tr->addReadConflictRange(conflictRange);
 				tr->addWriteConflictRange(conflictRange);
 
-				StorageMetadataType metadata(timer_int());
+				StorageMetadataType metadata(StorageMetadataType::currentTime());
 				metadataMap.set(tr, server.id(), metadata);
 
 				if (SERVER_KNOBS->TSS_HACK_IDENTITY_MAPPING) {
@@ -1521,7 +1521,7 @@ void seedShardServers(Arena& arena, CommitTransactionRef& tr, std::vector<Storag
 	tr.read_conflict_ranges.push_back_deep(arena, allKeys);
 	KeyBackedObjectMap<UID, StorageMetadataType, decltype(IncludeVersion())> metadataMap(serverMetadataKeys.begin,
 	                                                                                     IncludeVersion());
-	StorageMetadataType metadata(timer_int());
+	StorageMetadataType metadata(StorageMetadataType::currentTime());
 
 	for (auto& s : servers) {
 		tr.set(arena, serverTagKeyFor(s.id()), serverTagValue(server_tag[s.id()]));

flow/Arena.cpp

@@ -352,12 +352,14 @@ ArenaBlock* ArenaBlock::create(int dataSize, Reference<ArenaBlock>& next) {
 			b->bigSize = reqSize;
 			b->bigUsed = sizeof(ArenaBlock);
 
+#if !DEBUG_DETERMINISM
 			if (FLOW_KNOBS && g_allocation_tracing_disabled == 0 &&
 			    nondeterministicRandom()->random01() < (reqSize / FLOW_KNOBS->HUGE_ARENA_LOGGING_BYTES)) {
 				++g_allocation_tracing_disabled;
 				hugeArenaSample(reqSize);
 				--g_allocation_tracing_disabled;
 			}
+#endif
 			g_hugeArenaMemory.fetch_add(reqSize);
 
 			// If the new block has less free space than the old block, make the old block depend on it

flow/FastAlloc.cpp

@@ -527,12 +527,14 @@ void FastAllocator<Size>::getMagazine() {
 	// FIXME: We should be able to allocate larger magazine sizes here if we
 	// detect that the underlying system supports hugepages.  Using hugepages
 	// with smaller-than-2MiB magazine sizes strands memory.  See issue #909.
+#if !DEBUG_DETERMINISM
 	if (FLOW_KNOBS && g_allocation_tracing_disabled == 0 &&
 	    nondeterministicRandom()->random01() < (magazine_size * Size) / FLOW_KNOBS->FAST_ALLOC_LOGGING_BYTES) {
 		++g_allocation_tracing_disabled;
 		TraceEvent("GetMagazineSample").detail("Size", Size).backtrace();
 		--g_allocation_tracing_disabled;
 	}
+#endif
 	block = (void**)::allocate(magazine_size * Size, false);
 #endif
 

flow/SystemMonitor.cpp

@@ -43,7 +43,9 @@ double machineStartTime() {
 
 void systemMonitor() {
 	static StatisticsState statState = StatisticsState();
+#if !DEBUG_DETERMINISM
 	customSystemMonitor("ProcessMetrics", &statState, true);
+#endif
 }
 
 SystemStatistics getSystemStatistics() {

flow/flow.cpp

@@ -69,7 +69,7 @@ using namespace std::literals;
 
 const std::string_view StackLineage::name = "StackLineage"sv;
 
-#if (defined(__linux__) || defined(__FreeBSD__)) && defined(__AVX__) && !defined(MEMORY_SANITIZER)
+#if (defined(__linux__) || defined(__FreeBSD__)) && defined(__AVX__) && !defined(MEMORY_SANITIZER) && !DEBUG_DETERMINISM
 // For benchmarking; need a version of rte_memcpy that doesn't live in the same compilation unit as the test.
 void* rte_memcpy_noinline(void* __restrict __dest, const void* __restrict __src, size_t __n) {
 	return rte_memcpy(__dest, __src, __n);