diff --git a/examples/common/tracing/TraceDecoder.cpp b/examples/common/tracing/TraceDecoder.cpp index 2bb3c5ee213ce0..7aecfa2bacb08e 100644 --- a/examples/common/tracing/TraceDecoder.cpp +++ b/examples/common/tracing/TraceDecoder.cpp @@ -30,31 +30,43 @@ constexpr uint16_t kMaxLineLen = 4096; constexpr const char * jsonPrefix = " json\t"; -// Json keys -constexpr const char * kProtocolIdKey = "protocol_id"; -constexpr const char * kProtocolCodeKey = "protocol_opcode"; -constexpr const char * kSessionIdKey = "session_id"; -constexpr const char * kExchangeIdKey = "exchange_id"; -constexpr const char * kMessageCounterKey = "msg_counter"; -constexpr const char * kSecurityFlagsKey = "security_flags"; -constexpr const char * kMessageFlagsKey = "msg_flags"; -constexpr const char * kSourceNodeIdKey = "source_node_id"; -constexpr const char * kDestinationNodeIdKey = "dest_node_id"; -constexpr const char * kDestinationGroupIdKey = "group_id"; -constexpr const char * kExchangeFlagsKey = "exchange_flags"; -constexpr const char * kIsInitiatorKey = "is_initiator"; -constexpr const char * kNeedsAckKey = "is_ack_requested"; -constexpr const char * kAckMsgKey = "acknowledged_msg_counter"; -constexpr const char * kPayloadDataKey = "payload_hex"; -constexpr const char * kPayloadSizeKey = "payload_size"; -constexpr const char * kPayloadEncryptedDataKey = "payload_hex_encrypted"; -constexpr const char * kPayloadEncryptedSizeKey = "payload_size_encrypted"; -constexpr const char * kPayloadEncryptedBufferPtrKey = "buffer_ptr"; -constexpr const char * kSourceKey = "source"; -constexpr const char * kDestinationKey = "destination"; - namespace chip { namespace trace { +namespace { + +// Json keys +constexpr const char * kProtocolIdKey = "protocol_id"; +constexpr const char * kProtocolCodeKey = "protocol_opcode"; +constexpr const char * kSessionIdKey = "session_id"; +constexpr const char * kExchangeIdKey = "exchange_id"; +constexpr const char * kMessageCounterKey = "msg_counter"; +constexpr const char * kSecurityFlagsKey = "security_flags"; +constexpr const char * kMessageFlagsKey = "msg_flags"; +constexpr const char * kSourceNodeIdKey = "source_node_id"; +constexpr const char * kDestinationNodeIdKey = "dest_node_id"; +constexpr const char * kDestinationGroupIdKey = "group_id"; +constexpr const char * kExchangeFlagsKey = "exchange_flags"; +constexpr const char * kIsInitiatorKey = "is_initiator"; +constexpr const char * kNeedsAckKey = "is_ack_requested"; +constexpr const char * kAckMsgKey = "acknowledged_msg_counter"; +constexpr const char * kPayloadDataKey = "payload_hex"; +constexpr const char * kPayloadSizeKey = "payload_size"; +constexpr const char * kDirectionKey = "direction"; +constexpr const char * kPeerAddress = "peer_address"; + +bool IsOutbound(const Json::Value & json) +{ + VerifyOrReturnValue(json.isMember(kDirectionKey), false); + return strcmp(json[kDirectionKey].asCString(), "outbound") == 0; +} + +bool IsInbound(const Json::Value & json) +{ + VerifyOrReturnValue(json.isMember(kDirectionKey), false); + return strcmp(json[kDirectionKey].asCString(), "inbound") == 0; +} + +} // namespace using namespace logging; @@ -83,45 +95,8 @@ CHIP_ERROR TraceDecoder::ReadString(const char * str) str += strlen(jsonPrefix); Json::Reader reader; - - if (mJsonBuffer.empty()) - { - VerifyOrReturnError(reader.parse(str, mJsonBuffer), CHIP_ERROR_INVALID_ARGUMENT); - VerifyOrReturnError(mJsonBuffer.isMember(kPayloadDataKey) && mJsonBuffer.isMember(kPayloadSizeKey), - CHIP_ERROR_INCORRECT_STATE); - return CHIP_NO_ERROR; - } - Json::Value json; VerifyOrReturnError(reader.parse(str, json), CHIP_ERROR_INVALID_ARGUMENT); - - // If there is a source, then it means the previously saved payload is an encrypted to decode, otherwise - // the previously saved payload is the non encrypted version, and the current decoded one is the encrypted version. - if (mJsonBuffer.isMember(kSourceKey)) - { - json[kPayloadEncryptedDataKey] = mJsonBuffer[kPayloadDataKey]; - json[kPayloadEncryptedSizeKey] = mJsonBuffer[kPayloadSizeKey]; - } - else - { - auto data = json[kPayloadDataKey]; - auto size = json[kPayloadSizeKey]; - json[kPayloadDataKey] = mJsonBuffer[kPayloadDataKey]; - json[kPayloadSizeKey] = mJsonBuffer[kPayloadSizeKey]; - json[kPayloadEncryptedDataKey] = data; - json[kPayloadEncryptedSizeKey] = size; - } - mJsonBuffer.removeMember(kPayloadDataKey); - mJsonBuffer.removeMember(kPayloadSizeKey); - - // If there is additional data in the previously saved json copy all of it. - for (const auto & key : mJsonBuffer.getMemberNames()) - { - json[key] = mJsonBuffer[key]; - mJsonBuffer.removeMember(key); - } - - VerifyOrReturnError(json.isMember(kSourceKey) || json.isMember(kDestinationKey), CHIP_ERROR_INCORRECT_STATE); VerifyOrReturnError(json.isMember(kProtocolIdKey), CHIP_ERROR_INCORRECT_STATE); VerifyOrReturnError(json.isMember(kProtocolCodeKey), CHIP_ERROR_INCORRECT_STATE); @@ -138,20 +113,19 @@ CHIP_ERROR TraceDecoder::LogJSON(Json::Value & json) return CHIP_NO_ERROR; } - if (!mOptions.mEnableMessageInitiator && json.isMember(kDestinationKey)) + if (!mOptions.mEnableMessageInitiator && IsOutbound(json)) { return CHIP_NO_ERROR; } - if (!mOptions.mEnableMessageResponder && json.isMember(kSourceKey)) + if (!mOptions.mEnableMessageResponder && IsInbound(json)) { return CHIP_NO_ERROR; } - bool isResponse = json.isMember(kSourceKey) ? true : false; + bool isResponse = IsInbound(json); ReturnErrorOnFailure(LogAndConsumeProtocol(json)); ReturnErrorOnFailure(MaybeLogAndConsumeHeaderFlags(json)); - ReturnErrorOnFailure(MaybeLogAndConsumeEncryptedPayload(json)); ReturnErrorOnFailure(MaybeLogAndConsumePayload(json, isResponse)); ReturnErrorOnFailure(MaybeLogAndConsumeOthers(json)); @@ -168,26 +142,6 @@ CHIP_ERROR TraceDecoder::MaybeLogAndConsumeHeaderFlags(Json::Value & json) return CHIP_NO_ERROR; } -CHIP_ERROR TraceDecoder::MaybeLogAndConsumeEncryptedPayload(Json::Value & json) -{ - if (mOptions.mEnableDataEncryptedPayload) - { - size_t size = static_cast(json[kPayloadEncryptedSizeKey].asLargestUInt()); - if (size) - { - auto payload = json[kPayloadEncryptedDataKey].asString(); - auto bufferPtr = json[kPayloadEncryptedBufferPtrKey].asString(); - auto scopedIndent = ScopedLogIndentWithSize("Encrypted Payload", size); - Log("data", payload.c_str()); - Log("buffer_ptr", bufferPtr.c_str()); - } - } - json.removeMember(kPayloadEncryptedSizeKey); - json.removeMember(kPayloadEncryptedDataKey); - json.removeMember(kPayloadEncryptedBufferPtrKey); - return CHIP_NO_ERROR; -} - CHIP_ERROR TraceDecoder::MaybeLogAndConsumeOthers(Json::Value & json) { std::vector keys = json.getMemberNames(); @@ -218,8 +172,16 @@ CHIP_ERROR TraceDecoder::LogAndConsumeProtocol(Json::Value & json) chip::StringBuilderBase builder(protocolInfo, sizeof(protocolInfo)); - builder.Add(json.isMember(kSourceKey) ? "<< from " : ">> to "); - builder.Add(json.isMember(kSourceKey) ? json[kSourceKey].asCString() : json[kDestinationKey].asCString()); + builder.Add(IsInbound(json) ? "<< from " : ">> to "); + + if (json.isMember(kPeerAddress)) + { + builder.Add(json[kPeerAddress].asCString()); + } + else + { + builder.Add("UNKNOWN"); + } builder.Add(" "); auto msgCounter = static_cast(json[kMessageCounterKey].asLargestUInt()); @@ -258,11 +220,10 @@ CHIP_ERROR TraceDecoder::LogAndConsumeProtocol(Json::Value & json) ChipLogProgress(DataManagement, "%s", builder.c_str()); - json.removeMember(kSourceKey); - json.removeMember(kDestinationKey); json.removeMember(kSessionIdKey); json.removeMember(kExchangeIdKey); json.removeMember(kMessageCounterKey); + json.removeMember(kDirectionKey); return CHIP_NO_ERROR; } diff --git a/examples/common/tracing/TraceDecoder.h b/examples/common/tracing/TraceDecoder.h index cc8dbd2374f9d5..4e70f5f12f1535 100644 --- a/examples/common/tracing/TraceDecoder.h +++ b/examples/common/tracing/TraceDecoder.h @@ -42,7 +42,12 @@ class TraceDecoder : public TraceStream { char buffer[2048] = {}; snprintf(buffer, sizeof(buffer), " %s\t %s", tag.c_str(), data.c_str()); - ReadString(buffer); + CHIP_ERROR err = ReadString(buffer); + + if (err != CHIP_NO_ERROR) + { + ChipLogError(Automation, "Failed to add field: %" CHIP_ERROR_FORMAT, err.Format()); + } } void FinishEvent() override {} @@ -55,12 +60,10 @@ class TraceDecoder : public TraceStream CHIP_ERROR MaybeLogAndConsumeMessageFlags(Json::Value & value); CHIP_ERROR MaybeLogAndConsumeExchangeFlags(Json::Value & value); CHIP_ERROR MaybeLogAndConsumePayload(Json::Value & value, bool isResponse); - CHIP_ERROR MaybeLogAndConsumeEncryptedPayload(Json::Value & value); CHIP_ERROR MaybeLogAndConsumeOthers(Json::Value & value); private: TraceDecoderOptions mOptions; - Json::Value mJsonBuffer; }; } // namespace trace diff --git a/examples/common/tracing/TraceHandlers.cpp b/examples/common/tracing/TraceHandlers.cpp index d595580fa7619a..73f3bb7a71e2e3 100644 --- a/examples/common/tracing/TraceHandlers.cpp +++ b/examples/common/tracing/TraceHandlers.cpp @@ -233,7 +233,9 @@ void SecureMessageSentHandler(const TraceSecureMessageSentData * eventData) return; } - std::string jsonBody = "{"; + std::string jsonBody = "{ \"direction\": \"outbound\", "; + jsonBody += AsFirstJsonKey("peer_address", AsJsonString(eventData->peerAddress)); + jsonBody += ", "; jsonBody += PacketHeaderToJson(eventData->packetHeader); jsonBody += ", "; jsonBody += PayloadHeaderToJson(eventData->payloadHeader); @@ -255,7 +257,7 @@ void SecureMessageReceivedHandler(const TraceSecureMessageReceivedData * eventDa return; } - std::string jsonBody = "{"; + std::string jsonBody = "{ \"direction\": \"inbound\", "; jsonBody += AsFirstJsonKey("peer_address", AsJsonString(eventData->peerAddress)); jsonBody += ", "; jsonBody += PacketHeaderToJson(eventData->packetHeader); diff --git a/src/transport/Session.h b/src/transport/Session.h index 29ebf593a9b5e3..14139b56df9c00 100644 --- a/src/transport/Session.h +++ b/src/transport/Session.h @@ -27,7 +27,6 @@ #include #include #include -#include namespace chip { namespace Transport { diff --git a/src/transport/SessionManager.cpp b/src/transport/SessionManager.cpp index 456b0e547aa717..7b9ebaf0ad8f68 100644 --- a/src/transport/SessionManager.cpp +++ b/src/transport/SessionManager.cpp @@ -181,11 +181,13 @@ CHIP_ERROR SessionManager::PrepareMessage(const SessionHandle & sessionHandle, P return CHIP_ERROR_INTERNAL; } + PeerAddress destination_address = Transport::PeerAddress::Multicast(fabric->GetFabricId(), groupSession->GetGroupId()); + // Trace before any encryption MATTER_LOG_MESSAGE_SEND(chip::Tracing::OutgoingMessageType::kGroupMessage, &payloadHeader, &packetHeader, chip::ByteSpan(message->Start(), message->TotalLength())); - CHIP_TRACE_MESSAGE_SENT(payloadHeader, packetHeader, message->Start(), message->TotalLength()); + CHIP_TRACE_MESSAGE_SENT(payloadHeader, packetHeader, destination_address, message->Start(), message->TotalLength()); Crypto::SymmetricKeyContext * keyContext = groups->GetKeyContext(groupSession->GetFabricIndex(), groupSession->GetGroupId()); @@ -219,10 +221,12 @@ CHIP_ERROR SessionManager::PrepareMessage(const SessionHandle & sessionHandle, P .SetSessionId(session->GetPeerSessionId()) // .SetSessionType(Header::SessionType::kUnicastSession); + PeerAddress destination_address = session->GetPeerAddress(); + // Trace before any encryption MATTER_LOG_MESSAGE_SEND(chip::Tracing::OutgoingMessageType::kSecureSession, &payloadHeader, &packetHeader, chip::ByteSpan(message->Start(), message->TotalLength())); - CHIP_TRACE_MESSAGE_SENT(payloadHeader, packetHeader, message->Start(), message->TotalLength()); + CHIP_TRACE_MESSAGE_SENT(payloadHeader, packetHeader, destination_address, message->Start(), message->TotalLength()); CryptoContext::NonceStorage nonce; NodeId sourceNodeId = session->GetLocalScopedNodeId().GetNodeId(); @@ -252,10 +256,13 @@ CHIP_ERROR SessionManager::PrepareMessage(const SessionHandle & sessionHandle, P break; } + auto unauthenticated = sessionHandle->AsUnauthenticatedSession(); + PeerAddress destination_address = unauthenticated->GetPeerAddress(); + // Trace after all headers are settled. MATTER_LOG_MESSAGE_SEND(chip::Tracing::OutgoingMessageType::kUnauthenticated, &payloadHeader, &packetHeader, chip::ByteSpan(message->Start(), message->TotalLength())); - CHIP_TRACE_MESSAGE_SENT(payloadHeader, packetHeader, message->Start(), message->TotalLength()); + CHIP_TRACE_MESSAGE_SENT(payloadHeader, packetHeader, destination_address, message->Start(), message->TotalLength()); ReturnErrorOnFailure(payloadHeader.EncodeBeforeData(message)); diff --git a/src/transport/TraceMessage.h b/src/transport/TraceMessage.h index b8c5f87f7c8c1a..bf6cbaef99c861 100644 --- a/src/transport/TraceMessage.h +++ b/src/transport/TraceMessage.h @@ -40,10 +40,10 @@ #define _CHIP_TRACE_MESSAGE_INTERNAL(type, data, size) PW_TRACE_INSTANT_DATA(::chip::trace::kTraceMessageEvent, type, data, size); #endif // CHIP_CONFIG_TRANSPORT_TRACE_ENABLED && CHIP_CONFIG_TRANSPORT_PW_TRACE_ENABLED -#define CHIP_TRACE_MESSAGE_SENT(payloadHeader, packetHeader, data, dataLen) \ +#define CHIP_TRACE_MESSAGE_SENT(payloadHeader, packetHeader, peerAddress, data, dataLen) \ do \ { \ - const ::chip::trace::TraceSecureMessageSentData _trace_data{ &payloadHeader, &packetHeader, data, dataLen }; \ + const ::chip::trace::TraceSecureMessageSentData _trace_data{ &payloadHeader, &packetHeader, &peerAddress, data, dataLen }; \ _CHIP_TRACE_MESSAGE_INTERNAL(::chip::trace::kTraceMessageSentDataFormat, reinterpret_cast(&_trace_data), \ sizeof(_trace_data)); \ } while (0) @@ -58,14 +58,16 @@ } while (0) #else // CHIP_CONFIG_TRANSPORT_TRACE_ENABLED || CHIP_CONFIG_TRANSPORT_PW_TRACE_ENABLED -#define CHIP_TRACE_MESSAGE_SENT(payloadHeader, packetHeader, data, dataLen) \ +#define CHIP_TRACE_MESSAGE_SENT(payloadHeader, packetHeader, peerAddress, data, dataLen) \ do \ { \ + (void) peerAddress; \ } while (0) #define CHIP_TRACE_MESSAGE_RECEIVED(payloadHeader, packetHeader, session, peerAddress, data, dataLen) \ do \ { \ + (void) peerAddress; \ } while (0) #endif // CHIP_CONFIG_TRANSPORT_TRACE_ENABLED || CHIP_CONFIG_TRANSPORT_PW_TRACE_ENABLED @@ -81,6 +83,7 @@ struct TraceSecureMessageSentData { const PayloadHeader * payloadHeader; const PacketHeader * packetHeader; + const Transport::PeerAddress * peerAddress; const uint8_t * packetPayload; size_t packetSize; };