From e767860010685637ac112c99b39ee1054b94ae0e Mon Sep 17 00:00:00 2001 From: Balachandar Namasivayam Date: Mon, 7 Aug 2017 18:45:42 -0700 Subject: [PATCH] Addressed review comments. Changed current protocol version to match master Added operation details for operations that failed. --- fdbclient/ClientLogEvents.h | 90 ++++++++++++++++++++++++----------- fdbclient/CommitTransaction.h | 11 +++-- fdbclient/NativeAPI.actor.cpp | 6 +-- flow/Net2.actor.cpp | 2 +- 4 files changed, 75 insertions(+), 34 deletions(-) diff --git a/fdbclient/ClientLogEvents.h b/fdbclient/ClientLogEvents.h index 7dc7a27fef..3b983883b5 100644 --- a/fdbclient/ClientLogEvents.h +++ b/fdbclient/ClientLogEvents.h @@ -64,7 +64,7 @@ namespace FdbClientLogEvents { }; struct EventGet : public Event { - EventGet(double ts, double lat, int size, const Key &in_key) : Event(GET_LATENCY, ts), latency(lat), valueSize(size), key(printable(in_key)) { } + EventGet(double ts, double lat, int size, const KeyRef &in_key) : Event(GET_LATENCY, ts), latency(lat), valueSize(size), key(in_key) { } template Ar& serialize(Ar &ar) { if (!ar.isDeserializing) @@ -75,15 +75,15 @@ namespace FdbClientLogEvents { double latency; int valueSize; - std::string key; + Key key; void logEvent(std::string id) const { - TraceEvent("TransactionTrace_Get").detail("TransactionID", id).detail("Latency", latency).detail("ValueSizeBytes", valueSize).detail("Key", key); + TraceEvent("TransactionTrace_Get").detail("TransactionID", id).detail("Latency", latency).detail("ValueSizeBytes", valueSize).detail("Key", printable(key)); } }; struct EventGetRange : public Event { - EventGetRange(double ts, double lat, int size, const KeyRef &start_key, const KeyRef & end_key) : Event(GET_RANGE_LATENCY, ts), latency(lat), rangeSize(size), startKey(printable(start_key)), endKey(printable(end_key)) { } + EventGetRange(double ts, double lat, int size, const KeyRef &start_key, const KeyRef & end_key) : Event(GET_RANGE_LATENCY, ts), latency(lat), rangeSize(size), startKey(start_key), endKey(end_key) { } template Ar& serialize(Ar &ar) { if (!ar.isDeserializing) @@ -94,16 +94,15 @@ namespace FdbClientLogEvents { double latency; int rangeSize; - std::string startKey; - std::string endKey; + Key startKey; + Key endKey; void logEvent(std::string id) const { - TraceEvent("TransactionTrace_GetRange").detail("TransactionID", id).detail("Latency", latency).detail("RangeSizeBytes", rangeSize).detail("StartKey", startKey).detail("EndKey", endKey); + TraceEvent("TransactionTrace_GetRange").detail("TransactionID", id).detail("Latency", latency).detail("RangeSizeBytes", rangeSize).detail("StartKey", printable(startKey)).detail("EndKey", printable(endKey)); } }; struct EventCommit : public Event { - EventCommit() :Event(COMMIT_LATENCY, 0) {} EventCommit(double ts, double lat, int mut, int bytes, CommitTransactionRequest *commit_req) : Event(COMMIT_LATENCY, ts), latency(lat), numMutations(mut), commitBytes(bytes), req(*commit_req) { } template Ar& serialize(Ar &ar) { @@ -119,8 +118,6 @@ namespace FdbClientLogEvents { CommitTransactionRequest req; // Only CommitTransactionRef and Arena object within CommitTransactionRequest is serialized void logEvent(std::string id) const { - TraceEvent("TransactionTrace_Commit").detail("TransactionID", id).detail("Latency", latency).detail("NumMutations", numMutations).detail("CommitSizeBytes", commitBytes); - for (auto &read_range : req.transaction.read_conflict_ranges) { TraceEvent("TransactionTrace_Commit_ReadConflictRange").detail("TransactionID", id).detail("Begin", printable(read_range.begin)).detail("End", printable(read_range.end)); } @@ -132,36 +129,75 @@ namespace FdbClientLogEvents { for (auto &mutation : req.transaction.mutations) { TraceEvent("TransactionTrace_Commit_Mutation").detail("TransactionID", id).detail("Mutation", mutation.toString()); } + + TraceEvent("TransactionTrace_Commit").detail("TransactionID", id).detail("Latency", latency).detail("NumMutations", numMutations).detail("CommitSizeBytes", commitBytes); } }; - struct EventError : public Event { - EventError(EventType t, double ts, int err_code) : Event(t, ts), errCode(err_code) { } + struct EventGetError : public Event { + EventGetError(double ts, int err_code, const KeyRef &in_key) : Event(ERROR_GET, ts), errCode(err_code), key(in_key) { } template Ar& serialize(Ar &ar) { if (!ar.isDeserializing) - return Event::serialize(ar) & errCode; + return Event::serialize(ar) & errCode & key; else - return ar & errCode; + return ar & errCode & key; } + int errCode; + Key key; void logEvent(std::string id) const { - const char *eventName; - if(type == ERROR_GET) { - eventName = "TransactionTrace_GetError"; - } - else if(type == ERROR_GET_RANGE) { - eventName = "TransactionTrace_GetRangeError"; - } - else if(type == ERROR_COMMIT) { - eventName = "TransactionTrace_CommitError"; - } - else { - eventName = "TransactionTrace_Error"; + TraceEvent("TransactionTrace_GetError").detail("TransactionID", id).detail("ErrCode", errCode).detail("Key", printable(key)); + } + }; + + struct EventGetRangeError : public Event { + EventGetRangeError(double ts, int err_code, const KeyRef &start_key, const KeyRef & end_key) : Event(ERROR_GET_RANGE, ts), errCode(err_code), startKey(start_key), endKey(end_key) { } + + template Ar& serialize(Ar &ar) { + if (!ar.isDeserializing) + return Event::serialize(ar) & errCode & startKey & endKey; + else + return ar & errCode & startKey & endKey; + } + + int errCode; + Key startKey; + Key endKey; + + void logEvent(std::string id) const { + TraceEvent("TransactionTrace_GetRangeError").detail("TransactionID", id).detail("ErrCode", errCode).detail("StartKey", printable(startKey)).detail("EndKey", printable(endKey)); + } + }; + + struct EventCommitError : public Event { + EventCommitError(double ts, int err_code, CommitTransactionRequest *commit_req) : Event(ERROR_COMMIT, ts), errCode(err_code), req(*commit_req) { } + + template Ar& serialize(Ar &ar) { + if (!ar.isDeserializing) + return Event::serialize(ar) & errCode & req.transaction & req.arena; + else + return ar & errCode & req.transaction & req.arena; + } + + int errCode; + CommitTransactionRequest req; // Only CommitTransactionRef and Arena object within CommitTransactionRequest is serialized + + void logEvent(std::string id) const { + for (auto &read_range : req.transaction.read_conflict_ranges) { + TraceEvent("TransactionTrace_CommitError_ReadConflictRange").detail("TransactionID", id).detail("Begin", printable(read_range.begin)).detail("End", printable(read_range.end)); } - TraceEvent(SevWarn, eventName).detail("TransactionID", id).detail("Error", errCode).detail("Description", Error(errCode).what()); + for (auto &write_range : req.transaction.write_conflict_ranges) { + TraceEvent("TransactionTrace_CommitError_WriteConflictRange").detail("TransactionID", id).detail("Begin", printable(write_range.begin)).detail("End", printable(write_range.end)); + } + + for (auto &mutation : req.transaction.mutations) { + TraceEvent("TransactionTrace_CommitError_Mutation").detail("TransactionID", id).detail("Mutation", mutation.toString()); + } + + TraceEvent("TransactionTrace_CommitError").detail("TransactionID", id).detail("ErrCode", errCode); } }; } diff --git a/fdbclient/CommitTransaction.h b/fdbclient/CommitTransaction.h index 71d5881161..d5ada27b3f 100644 --- a/fdbclient/CommitTransaction.h +++ b/fdbclient/CommitTransaction.h @@ -26,8 +26,8 @@ struct MutationRef { static const int OVERHEAD_BYTES = 12; //12 is the size of Header in MutationList entries - enum Type : uint8_t { SetValue=0, ClearRange, AddValue, DebugKeyRange, DebugKey, NoOp, And, Or, Xor, AppendIfFits, AvailableForReuse, Reserved_For_LogProtocolMessage /* See fdbserver/LogProtocolMessage.h */, Max, Min, SetVersionstampedKey, SetVersionstampedValue, MAX_ATOMIC_OP, END }; // END should be the last element - const char * typeString[END] = { "SetValue", "ClearRange", "AddValue", "DebugKeyRange", "DebugKey", "NoOp", "And", "Or", "Xor", "AppendIfFits", "AvailableForReuse", "Reserved_For_LogProtocolMessage", "Max", "Min", "SetVersionstampedKey", "SetVersionstampedValue", "MAX_ATOMIC_OP" }; + enum Type : uint8_t { SetValue=0, ClearRange, AddValue, DebugKeyRange, DebugKey, NoOp, And, Or, Xor, AppendIfFits, AvailableForReuse, Reserved_For_LogProtocolMessage /* See fdbserver/LogProtocolMessage.h */, Max, Min, SetVersionstampedKey, SetVersionstampedValue, MAX_ATOMIC_OP }; + const char * typeString[MAX_ATOMIC_OP] = { "SetValue", "ClearRange", "AddValue", "DebugKeyRange", "DebugKey", "NoOp", "And", "Or", "Xor", "AppendIfFits", "AvailableForReuse", "Reserved_For_LogProtocolMessage", "Max", "Min", "SetVersionstampedKey", "SetVersionstampedValue" }; // This is stored this way for serialization purposes. uint8_t type; StringRef param1, param2; @@ -39,7 +39,12 @@ struct MutationRef { int expectedSize() const { return param1.size() + param2.size(); } std::string toString() const { - return format("code: %s param1: %s param2: %s", typeString[type], printable(param1).c_str(), printable(param2).c_str()); + if (type < MutationRef::MAX_ATOMIC_OP) { + return format("code: %s param1: %s param2: %s", typeString[type], printable(param1).c_str(), printable(param2).c_str()); + } + else { + return format("code: %s param1: %s param2: %s", "Invalid", printable(param1).c_str(), printable(param2).c_str()); + } } template diff --git a/fdbclient/NativeAPI.actor.cpp b/fdbclient/NativeAPI.actor.cpp index 43e32c6367..bc67d74667 100644 --- a/fdbclient/NativeAPI.actor.cpp +++ b/fdbclient/NativeAPI.actor.cpp @@ -1364,7 +1364,7 @@ ACTOR Future> getValue( Future version, Key key, Databa Void _ = wait(delay(CLIENT_KNOBS->WRONG_SHARD_SERVER_DELAY, info.taskID)); } else { if (trLogInfo) - trLogInfo->addLog(FdbClientLogEvents::EventError(FdbClientLogEvents::ERROR_GET, startTimeD, static_cast(e.code()))); + trLogInfo->addLog(FdbClientLogEvents::EventGetError(startTimeD, static_cast(e.code()), key)); throw e; } } @@ -1883,7 +1883,7 @@ ACTOR Future> getRangeWrapper(Database cx, Reference< } catch (Error &e) { if (trLogInfo) - trLogInfo->addLog(FdbClientLogEvents::EventError(FdbClientLogEvents::ERROR_GET_RANGE, startTime, static_cast(e.code()))); + trLogInfo->addLog(FdbClientLogEvents::EventGetRangeError(startTime, static_cast(e.code()), begin.getKey(), end.getKey())); throw; } } @@ -2544,7 +2544,7 @@ ACTOR static Future tryCommit( Database cx, Reference if (e.code() != error_code_past_version && e.code() != error_code_not_committed && e.code() != error_code_database_locked) TraceEvent(SevError, "tryCommitError").error(e); if (trLogInfo) - trLogInfo->addLog(FdbClientLogEvents::EventError(FdbClientLogEvents::ERROR_COMMIT, startTime, static_cast(e.code()))); + trLogInfo->addLog(FdbClientLogEvents::EventCommitError(startTime, static_cast(e.code()), req)); throw; } } diff --git a/flow/Net2.actor.cpp b/flow/Net2.actor.cpp index 28c9a74e43..ddbfb7ae08 100644 --- a/flow/Net2.actor.cpp +++ b/flow/Net2.actor.cpp @@ -52,7 +52,7 @@ using namespace boost::asio::ip; // These impact both communications and the deserialization of certain zookeeper, database and IKeyValueStore keys // xyzdev // vvvv -uint64_t currentProtocolVersion = 0x0FDB00A550010001LL; +uint64_t currentProtocolVersion = 0x0FDB00A551000001LL; uint64_t compatibleProtocolVersionMask = 0xffffffffffff0000LL; uint64_t minValidProtocolVersion = 0x0FDB00A200060001LL;