Implemented Traceable for printable types

fdbclient/FDBTypes.h

@@ -213,6 +213,23 @@ struct KeyRangeRef {
 	};
 };
 
+template<>
+struct Traceable<KeyRangeRef> : std::true_type {
+	static std::string toString(const KeyRangeRef& value) {
+		auto begin = Traceable<StringRef>::toString(value.begin);
+		auto end = Traceable<StringRef>::toString(value.end);
+		std::string result;
+		result.reserve(begin.size() + end.size() + 3);
+		std::copy(begin.begin(), begin.end(), std::back_inserter(result));
+		result.push_back(' ');
+		result.push_back('-');
+		result.push_back(' ');
+		std::copy(end.begin(), end.end(), std::back_inserter(result));
+		return result;
+	}
+};
+
+
 inline KeyRangeRef operator & (const KeyRangeRef& lhs, const KeyRangeRef& rhs) {
 	KeyRef b = std::max(lhs.begin, rhs.begin), e = std::min(lhs.end, rhs.end);
 	if (e < b)
@@ -263,6 +280,13 @@ struct KeyValueRef {
 	};
 };
 
+template<>
+struct Traceable<KeyValueRef> : std::true_type {
+	static std::string toString(const KeyValueRef& value) {
+		return Traceable<KeyRef>::toString(value.key) + format(":%d", value.value.size());
+	}
+};
+
 typedef Standalone<KeyRef> Key;
 typedef Standalone<ValueRef> Value;
 typedef Standalone<KeyRangeRef> KeyRange;

fdbserver/IDiskQueue.h

@@ -37,7 +37,7 @@ public:
 		location() : hi(0), lo(0) {}
 		location(int64_t lo) : hi(0), lo(lo) {}
 		location(int64_t hi, int64_t lo) : hi(hi), lo(lo) {}
-		operator std::string() { return format("%lld.%lld", hi, lo); }  // FIXME: Return a 'HumanReadableDescription' instead of std::string, make TraceEvent::detail accept that (for safety)
+		operator std::string() const { return format("%lld.%lld", hi, lo); }  // FIXME: Return a 'HumanReadableDescription' instead of std::string, make TraceEvent::detail accept that (for safety)
 
 		template<class Ar>
 		void serialize_unversioned(Ar& ar) {
@@ -81,6 +81,13 @@ public:
 	virtual StorageBytes getStorageBytes() = 0;
 };
 
+template<>
+struct Traceable<IDiskQueue::location> : std::true_type {
+	static std::string toString(const IDiskQueue::location& value) {
+		return value;
+	}
+};
+
 // FIXME: One should be able to use SFINAE to choose between serialize and serialize_unversioned.
 template <class Ar> void load( Ar& ar, IDiskQueue::location& loc ) { loc.serialize_unversioned(ar); }
 template <class Ar> void save( Ar& ar, const IDiskQueue::location& loc ) { const_cast<IDiskQueue::location&>(loc).serialize_unversioned(ar); }

flow/ActorCollection.actor.cpp

@@ -60,14 +60,6 @@ ACTOR Future<Void> actorCollection( FutureStream<Future<Void>> addActor, int* pC
 	}
 }
 
-template<>
-struct Traceable<std::string> : std::true_type {
-	template<class Str>
-	static std::string toString(Str&& s) {
-		return std::forward<Str>(s);
-	}
-};
-
 template<class T, class U>
 struct Traceable<std::pair<T, U>> {
 	static constexpr bool value = Traceable<T>::value && Traceable<U>::value;
@@ -90,24 +82,45 @@ TEST_CASE("/flow/TraceEvent") {
 	state unsigned i;
 	state double startTime;
 	state std::vector<std::string> strings;
+	state std::vector<int> keyIdx;
+	state std::vector<int> pairRnd;
+	state std::vector<int> num;
+	state std::vector<double> doub;
+	state std::vector<int> strIdx;
 	strings.reserve(10000);
+	keyIdx.reserve(1e6);
+	pairRnd.reserve(1e6);
+	num.reserve(1e6);
+	doub.reserve(1e6);
+	strIdx.reserve(1e6);
 	for (i = 0; i < 100; ++i) {
 		for (int j = 0; j < 100; ++j) {
 			strings.emplace_back(g_random->randomAlphaNumeric(g_random->randomInt(1, 30)));
 		}
 		wait(delay(0));
 	}
+	for (i = 0; i < 1e6; ++i) {
+		keyIdx.emplace_back(g_random->randomInt(0, strings.size()));
+		pairRnd.emplace_back(g_random->randomInt(-1000, 1000));
+		num.emplace_back(g_random->randomInt(0, 1000));
+		doub.emplace_back(g_random->random01());
+		strIdx.emplace_back(g_random->randomInt(0, strings.size()));
+	}
 	TraceEvent("pairsfilled")
 		.detail("MemoryUsage", getMemoryUsage());
+	printf("Sleeping for 20 seconds - attach perf now to PID %d\n", getpid());
+	wait(delay(20));
+	printf("Done sleeping\n");
 	startTime = g_network->now();
 	for (i = 0; i < 100000; ++i) {
 		for (unsigned j = 0; j < 100; ++j) {
-			StringRef key(strings[g_random->randomInt(0, strings.size())]);
+			int idx = (i+1)*j % keyIdx.size();
-			auto p = std::make_pair(key, g_random->randomInt(-1000, 1000));
+			StringRef key(strings[keyIdx[idx]]);
+			auto p = std::make_pair(key, pairRnd[idx]);
 			TraceEvent("TestTraceLineNoDebug")
-				.detail("Num", g_random->randomInt(0, 1000))
+				.detail("Num", num[idx])
-				.detail("Double", g_random->random01())
+				.detail("Double", doub[idx])
-				.detail("str", strings[g_random->randomInt(0, strings.size())])
+				.detail("str", strings[strIdx[idx]])
 				.detail("pair", p);
 		}
 		wait(delay(0));
@@ -117,17 +130,20 @@ TEST_CASE("/flow/TraceEvent") {
 	startTime = g_network->now();
 	for (i = 0; i < 1000000; ++i) {
 		for (unsigned j = 0; j < 100; ++j) {
-			StringRef key(strings[g_random->randomInt(0, strings.size())]);
+			int idx = (i+1)*j % keyIdx.size();
-			auto p = std::make_pair(key, g_random->randomInt(-1000, 1000));
+			StringRef key(strings[keyIdx[idx]]);
+			auto p = std::make_pair(key, pairRnd[idx]);
 			TraceEvent(SevDebug, "TestTraceLineDebug")
-				.detail("Num", g_random->randomInt(0, 1000))
+				.detail("Num", num[idx])
-				.detail("Double", g_random->random01())
+				.detail("Double", doub[idx])
-				.detail("str", strings[g_random->randomInt(0, strings.size())])
+				.detail("str", strings[strIdx[idx]])
 				.detail("pair", p);
 		}
 		wait(delay(0));
 	}
 	TraceEvent("TraceDuration")
 		.detail("Time", g_network->now() - startTime);
+	printf("benchmark done\n", getpid());
+	wait(delay(10));
 	return Void();
 }

flow/Arena.h

@@ -33,6 +33,7 @@
 #include <limits>
 #include <set>
 #include <type_traits>
+#include <sstream>
 
 // TrackIt is a zero-size class for tracking constructions, destructions, and assignments of instances
 // of a class.  Just inherit TrackIt<T> from T to enable tracking of construction and destruction of
@@ -559,15 +560,34 @@ public:
 	}
 
 	std::string toString() const { return std::string( (const char*)data, length ); }
+
+	static bool isPrintable(char c) { return c > 32 && c < 127; }
 	std::string printable() const {
-		std::string s;
+		std::string result;
-		for (int i = 0; i<length; i++) {
+		int nonPrintables = 0;
-			uint8_t b = (*this)[i];
+		int numBackslashes = 0;
-			if (b >= 32 && b < 127 && b != '\\') s += (char)b;
+		for (auto c : *this) {
-			else if (b == '\\') s += "\\\\";
+			if (!isPrintable(c)) {
-			else s += format("\\x%02x", b);
+				++nonPrintables;
+			} else if (c == '\\') {
+				++numBackslashes;
 			}
-		return s;
+		}
+		result.reserve(size() - nonPrintables + (nonPrintables * 4) + numBackslashes);
+		for (auto c : *this) {
+			if (isPrintable(c)) {
+				result.push_back(c);
+			} else if (c == '\\') {
+				result.push_back('\\');
+				result.push_back('\\');
+			} else {
+				result.push_back('\\');
+				result.push_back('x');
+				result.push_back(base16Char((c / 16) % 16));
+				result.push_back(base16Char(c % 16));
+			}
+		}
+		return result;
 	}
 
 	std::string toHexString(int limit = -1) const {
@@ -655,7 +675,7 @@ private:
 template<>
 struct Traceable<StringRef> : std::true_type {
 	static std::string toString(const StringRef& value) {
-		return value.toString();
+		return value.printable();
 	}
 };
 
@@ -873,6 +893,26 @@ private:
 		m_capacity = requiredCapacity;
 	}
 };
+
+template<class T>
+struct Traceable<VectorRef<T>> {
+	constexpr static bool value = Traceable<T>::value;
+
+	static std::string toString(const VectorRef<T>& value) {
+		std::stringstream ss;
+		bool first = true;
+		for (const auto& v : value) {
+			if (first) {
+				first = false;
+			} else {
+				ss << ' ';
+			}
+			ss << Traceable<T>::toString(v);
+		}
+		return ss.str();
+	}
+};
+
 template <class Archive, class T>
 inline void load( Archive& ar, VectorRef<T>& value ) {
 	// FIXME: range checking for length, here and in other serialize code

flow/Trace.h

@@ -135,6 +135,46 @@ private:
 
 struct DynamicEventMetric;
 
+template<class IntType>
+char base16Char(IntType c) {
+	switch (c) {
+		case 0:
+			return '0';
+		case 1:
+			return '1';
+		case 2:
+			return '2';
+		case 3:
+			return '3';
+		case 4:
+			return '4';
+		case 5:
+			return '5';
+		case 6:
+			return '6';
+		case 7:
+			return '7';
+		case 8:
+			return '8';
+		case 9:
+			return '9';
+		case 10:
+			return 'a';
+		case 11:
+			return 'b';
+		case 12:
+			return 'c';
+		case 13:
+			return 'd';
+		case 14:
+			return 'e';
+		case 15:
+			return 'f';
+		default:
+			UNSTOPPABLE_ASSERT(false);
+	}
+}
+
 // forward declare format from flow.h as we
 // can't include flow.h here
 std::string format(const char* form, ...);
@@ -176,7 +216,94 @@ struct Traceable<UID> : std::true_type {
 	}
 };
 
+template<>
+struct Traceable<const char*> : std::true_type {
+	static bool isPrintable(char c) { return c > 32 && c < 127; }
+	static std::string toString(const char* value) {
+		// if all characters are printable ascii, we simply return the string
+		int nonPrintables = 0;
+		int numBackslashes = 0;
+		auto val = value;
+		int size = 0;
+		while (auto c = *(val++)) {
+			++size;
+			if (!Traceable<const char*>::isPrintable(c)) {
+				++nonPrintables;
+			} else if (c == '\\') {
+				++numBackslashes;
+			}
+		}
+		if (nonPrintables == 0 && numBackslashes == 0) {
+			return std::string(value);
+		}
+		std::string result;
+		result.reserve(size - nonPrintables + (nonPrintables * 4) + numBackslashes);
+		while (auto c = *(val++)) {
+			if (Traceable<const char*>::isPrintable(c)) {
+				result.push_back(c);
+			} else if (c == '\\') {
+				result.push_back('\\');
+				result.push_back('\\');
+			} else {
+				result.push_back('\\');
+				result.push_back('x');
+				result.push_back(base16Char((c / 16) % 16));
+				result.push_back(base16Char(c % 16));
+			}
+		}
+		return result;
+	}
+};
 
+template<size_t S>
+struct Traceable<char[S]> : std::true_type {
+	static std::string toString(const char* value) {
+		return Traceable<const char*>::toString(value);
+	}
+};
+
+template<>
+struct Traceable<char*> : std::true_type {
+	static std::string toString(const char* value) {
+		return Traceable<const char*>::toString(value);
+	}
+};
+
+template<>
+struct Traceable<std::string> : std::true_type {
+	template<class Str>
+	static std::string toString(Str&& value) {
+		// if all characters are printable ascii, we simply return the string
+		int nonPrintables = 0;
+		int numBackslashes = 0;
+		for (auto c : value) {
+			if (!Traceable<const char*>::isPrintable(c)) {
+				++nonPrintables;
+			} else if (c == '\\') {
+				++numBackslashes;
+			}
+		}
+		if (nonPrintables == 0 && numBackslashes == 0) {
+			return std::forward<Str>(value);
+		}
+		std::string result;
+		result.reserve(value.size() - nonPrintables + (nonPrintables * 4) + numBackslashes);
+		for (auto c : value) {
+			if (Traceable<const char*>::isPrintable(c)) {
+				result.push_back(c);
+			} else if (c == '\\') {
+				result.push_back('\\');
+				result.push_back('\\');
+			} else {
+				result.push_back('\\');
+				result.push_back('x');
+				result.push_back(base16Char((c / 16) % 16));
+				result.push_back(base16Char(c % 16));
+			}
+		}
+		return result;
+	}
+};
 
 template<class T>
 struct SpecialTraceMetricType
@@ -244,21 +371,6 @@ struct TraceEvent {
 		}
 		return *this;
 	}
-	TraceEvent& detail(std::string key, std::string value) {
-		if (enabled && init()) {
-			init();
-			addMetric(key.c_str(), value, value);
-			return detailImpl(std::string(key), std::move(value), false);
-		}
-		return *this;
-	}
-	TraceEvent& detail(const char* key, std::string value) {
-		if (enabled && init()) {
-			addMetric(key, value, value);
-			return detailImpl(std::string(key), std::move(value), false);
-		}
-		return *this;
-	}
 	TraceEvent& detailf( std::string key, const char* valueFormat, ... );
 private:
 	template<class T>