First successful negative run

fdbserver/SkipList.cpp

@@ -834,16 +834,25 @@ void ConflictBatch::addTransaction(const CommitTransactionRef& tr, Version newOl
 	Arena& arena = transactionInfo.arena();
 	TransactionInfo* info = new (arena) TransactionInfo;
 	info->reportConflictingKeys = tr.report_conflicting_keys;
+	bool tooOld = tr.read_snapshot < newOldestVersion && tr.read_conflict_ranges.size();
+	if (tooOld && ignoreTooOld()) {
+		bugs->hit();
+		tooOld = false;
+	}
 
-	if (tr.read_snapshot < newOldestVersion && tr.read_conflict_ranges.size() && !ignoreTooOld()) {
+	if (tooOld) {
 		info->tooOld = true;
 	} else {
 		info->tooOld = false;
 		if (!ignoreReadSet()) {
 			info->readRanges.resize(arena, tr.read_conflict_ranges.size());
+		} else {
+			bugs->hit();
 		}
 		if (!ignoreWriteSet()) {
 			info->writeRanges.resize(arena, tr.write_conflict_ranges.size());
+		} else {
+			bugs->hit();
 		}
 
 		for (int r = 0; r < info->readRanges.size(); r++) {

fdbserver/workloads/ResolverBug.actor.cpp

@@ -32,6 +32,7 @@ struct ResolverBugWorkload : TestWorkload {
 	ResolverBug resolverBug;
 	Standalone<VectorRef<KeyValueRef>> cycleOptions;
 	KeyRef controlKey = "workload_control"_sr;
+	Promise<Void> bugFound;
 
 	ResolverBugWorkload(WorkloadContext const& wcx) : TestWorkload(wcx) {
 		disableFailureInjections = getOption(options, "disableFailureInjections"_sr, true);
@@ -103,7 +104,6 @@ struct ResolverBugWorkload : TestWorkload {
 			BaseTraceEvent* trace = std::any_cast<BaseTraceEvent*>(data);
 			if (trace->getSeverity() == SevError) {
 				bug->bugFound = true;
-				TraceEvent("NegativeTestSuccess").log();
 			}
 		}
 	};
@@ -126,13 +126,8 @@ struct ResolverBugWorkload : TestWorkload {
 
 	ACTOR static Future<Void> _start(ResolverBugWorkload* self, Database cx) {
 		state Reference<TestWorkload> cycle;
-		state std::shared_ptr<ResolverBug> bug = SimBugInjector().get<ResolverBug>(ResolverBugID());
-		state Future<Void> f = Never();
-		if (self->clientId == 0) {
-			f = driveWorkload(bug, self->clientCount);
-		}
-		while (!bug->bugFound) {
-			ASSERT(!f.isReady());
+		state std::shared_ptr<ResolverBug> bug = SimBugInjector().get<ResolverBug>(ResolverBugID(), true);
+		loop {
 			wait(waitForPhase(bug, 1));
 			cycle = self->createCycle();
 			wait(cycle->setup(cx));
@@ -144,10 +139,27 @@ struct ResolverBugWorkload : TestWorkload {
 			wait(success(cycle->check(cx)));
 			bug->cycleState[self->clientId] = 3;
 		}
-		return Void();
 	}
 
-	Future<Void> start(const Database& cx) override { return _start(this, cx->clone()); }
+	ACTOR static Future<Void> onBug(std::shared_ptr<ResolverBug> bug) {
+		loop {
+			if (bug->bugFound) {
+				TraceEvent("NegativeTestSuccess").log();
+				return Void();
+			}
+			wait(delay(0.5));
+		}
+	}
+
+	Future<Void> start(const Database& cx) override {
+		std::vector<Future<Void>> futures;
+		auto bug = SimBugInjector().get<ResolverBug>(ResolverBugID(), true);
+		if (clientId == 0) {
+			futures.push_back(driveWorkload(bug, clientCount));
+		}
+		futures.push_back(_start(this, cx->clone()));
+		return onBug(bug) || waitForAll(futures);
+	}
 	Future<bool> check(Database const& cx) override { return true; };
 
 private:

flow/ProcessEvents.cpp

@@ -44,7 +44,9 @@ struct ProcessEventsImpl {
 	struct Triggering {
 		bool& value;
 		explicit Triggering(bool& value) : value(value) {
-			ASSERT(!value);
+			if (value) {
+				ASSERT(false);
+			}
 			value = true;
 		}
 		~Triggering() { value = false; }

flow/SimBugInjector.cpp

@@ -22,6 +22,7 @@
 #include "flow/network.h"
 
 #include <typeindex>
+#include <boost/core/demangle.hpp>
 
 namespace {
 
@@ -30,11 +31,38 @@ struct SimBugInjectorImpl {
 	std::unordered_map<std::type_index, std::shared_ptr<ISimBug>> bugs;
 };
 
+struct ISimBugImpl {
+	unsigned numHits = 0;
+	static ISimBugImpl* get(void* self) { return reinterpret_cast<ISimBugImpl*>(self); }
+};
+
 SimBugInjectorImpl* simBugInjector = nullptr;
 
 } // namespace
 
-ISimBug::~ISimBug() {}
+ISimBug::ISimBug() : impl(new ISimBugImpl()) {}
+
+ISimBug::~ISimBug() {
+	delete ISimBugImpl::get(impl);
+}
+
+std::string ISimBug::name() const {
+	auto const& typeInfo = typeid(*this);
+	return boost::core::demangle(typeInfo.name());
+}
+
+void ISimBug::hit() {
+	++ISimBugImpl::get(impl)->numHits;
+	TraceEvent(SevWarnAlways, "BugInjected").detail("Name", name()).detail("NumHits", numHits()).log();
+	this->onHit();
+}
+
+void ISimBug::onHit() {}
+
+unsigned ISimBug::numHits() const {
+	return ISimBugImpl::get(impl)->numHits;
+}
+
 IBugIdentifier::~IBugIdentifier() {}
 
 bool SimBugInjector::isEnabled() const {
@@ -63,8 +91,11 @@ void SimBugInjector::reset() {
 	}
 }
 
-std::shared_ptr<ISimBug> SimBugInjector::getImpl(const IBugIdentifier& id) const {
-	if (!isEnabled()) {
+std::shared_ptr<ISimBug> SimBugInjector::getImpl(const IBugIdentifier& id, bool getDisabled /* = false */) const {
+	if (!simBugInjector) {
+		return {};
+	}
+	if (!getDisabled && !isEnabled()) {
 		return {};
 	}
 	auto it = simBugInjector->bugs.find(std::type_index(typeid(id)));

flow/Trace.cpp

@@ -1307,10 +1307,6 @@ BaseTraceEvent& BaseTraceEvent::backtrace(const std::string& prefix) {
 }
 
 void BaseTraceEvent::log() {
-	if (g_traceProcessEvents) {
-		auto name = fmt::format("TraceEvent::{}", type);
-		ProcessEvents::trigger(StringRef(name), this, success());
-	}
 	if (!logged) {
 		init();
 		++g_allocation_tracing_disabled;
@@ -1336,6 +1332,10 @@ void BaseTraceEvent::log() {
 				if (isNetworkThread()) {
 					TraceEvent::eventCounts[severity / 10]++;
 				}
+				if (g_traceProcessEvents) {
+					auto name = fmt::format("TraceEvent::{}", type);
+					ProcessEvents::trigger(StringRef(name), this, success());
+				}
 				g_traceLog.writeEvent(fields, trackingKey, severity > SevWarnAlways);
 
 				if (g_traceLog.isOpen()) {

flow/include/flow/SimBugInjector.h

@@ -38,8 +38,28 @@
  * SimBugInjector.
  */
 class ISimBug : std::enable_shared_from_this<ISimBug> {
+	void* impl;
+	virtual void onHit();
+
 public:
+	ISimBug();
 	virtual ~ISimBug();
+	/**
+	 * The name of the bug. By default this will return the class name (using typeid and boost::core::demangle). This is
+	 * supposed to be a human-readable string which can be used to identify the bug when it appears in traces.
+	 *
+	 * @return A human readable string for this bug.
+	 */
+	virtual std::string name() const;
+	/**
+	 * Should be called every time this bug is hit. This method can't be overridden. However, it will call `onHit` which
+	 * can be overriden by a child.
+	 */
+	void hit();
+	/**
+	 * @return Number of times this bug has been hit (since last call to `SimBugInjector::reset`
+	 */
+	unsigned numHits() const;
 };
 
 /*
@@ -95,15 +115,15 @@ public:
 	 * @post enabled(bug(id)) -> result is valid else result is nullptr
 	 */
 	template <class T>
-	std::shared_ptr<T> get(IBugIdentifier const& id) {
-		auto res = getImpl(id);
+	std::shared_ptr<T> get(IBugIdentifier const& id, bool getDisabled = false) {
+		auto res = getImpl(id, getDisabled);
 		if (!res) {
 			return {};
 		}
 		return std::dynamic_pointer_cast<T>(res);
 	}
 
-	std::shared_ptr<ISimBug> getImpl(IBugIdentifier const& id) const;
+	std::shared_ptr<ISimBug> getImpl(IBugIdentifier const& id, bool getDisabled = false) const;
 
 	/**
 	 * Returns the ISimBug instance associated with id if it already exists. Otherwise it will first create it. It is a

tests/negative/ResolverIgnoreTooOld.toml

@@ -1,6 +1,12 @@
+[[knobs]]
+enable_version_vector = false
+max_read_transaction_life_versions = 1000000
+max_write_transaction_life_versions = 1000000
+
 [[test]]
 testTitle = "ResolverIgnoreTooOld"
 
 [[test.workload]]
 testName = "ResolverBug"
-ignoreTooOldProbability = 0.1
+# old transactions are rare in the first place, so we ignore all of them to make corruptions likely
+ignoreTooOldProbability = 1.0