Skip to content

Commit 7fc3ccb

Browse files
andy31415restyled-commitsandreilitvin
authored
Make tracedecoder not stateful and ensure both sent and received messages are logged (#27860)
* Make TraceDecoder not stateful, log inbound/outbount * Restyle * Ensure sending message data has destination peer address * Restyle * Add missing comma * Restyle * Remove unused constants * Restyled by clang-format * Apply code review comments * Restyled by clang-format * Code review fix * Avoid unused variable errors * Restyle --------- Co-authored-by: Restyled.io <[email protected]> Co-authored-by: Andrei Litvin <[email protected]>
1 parent 77b8d9f commit 7fc3ccb

File tree

6 files changed

+75
-100
lines changed

6 files changed

+75
-100
lines changed

‎examples/common/tracing/TraceDecoder.cpp

+49-88
Original file line numberDiff line numberDiff line change
@@ -30,31 +30,43 @@
3030
constexpr uint16_t kMaxLineLen = 4096;
3131
constexpr const char * jsonPrefix = " json\t";
3232

33-
// Json keys
34-
constexpr const char * kProtocolIdKey = "protocol_id";
35-
constexpr const char * kProtocolCodeKey = "protocol_opcode";
36-
constexpr const char * kSessionIdKey = "session_id";
37-
constexpr const char * kExchangeIdKey = "exchange_id";
38-
constexpr const char * kMessageCounterKey = "msg_counter";
39-
constexpr const char * kSecurityFlagsKey = "security_flags";
40-
constexpr const char * kMessageFlagsKey = "msg_flags";
41-
constexpr const char * kSourceNodeIdKey = "source_node_id";
42-
constexpr const char * kDestinationNodeIdKey = "dest_node_id";
43-
constexpr const char * kDestinationGroupIdKey = "group_id";
44-
constexpr const char * kExchangeFlagsKey = "exchange_flags";
45-
constexpr const char * kIsInitiatorKey = "is_initiator";
46-
constexpr const char * kNeedsAckKey = "is_ack_requested";
47-
constexpr const char * kAckMsgKey = "acknowledged_msg_counter";
48-
constexpr const char * kPayloadDataKey = "payload_hex";
49-
constexpr const char * kPayloadSizeKey = "payload_size";
50-
constexpr const char * kPayloadEncryptedDataKey = "payload_hex_encrypted";
51-
constexpr const char * kPayloadEncryptedSizeKey = "payload_size_encrypted";
52-
constexpr const char * kPayloadEncryptedBufferPtrKey = "buffer_ptr";
53-
constexpr const char * kSourceKey = "source";
54-
constexpr const char * kDestinationKey = "destination";
55-
5633
namespace chip {
5734
namespace trace {
35+
namespace {
36+
37+
// Json keys
38+
constexpr const char * kProtocolIdKey = "protocol_id";
39+
constexpr const char * kProtocolCodeKey = "protocol_opcode";
40+
constexpr const char * kSessionIdKey = "session_id";
41+
constexpr const char * kExchangeIdKey = "exchange_id";
42+
constexpr const char * kMessageCounterKey = "msg_counter";
43+
constexpr const char * kSecurityFlagsKey = "security_flags";
44+
constexpr const char * kMessageFlagsKey = "msg_flags";
45+
constexpr const char * kSourceNodeIdKey = "source_node_id";
46+
constexpr const char * kDestinationNodeIdKey = "dest_node_id";
47+
constexpr const char * kDestinationGroupIdKey = "group_id";
48+
constexpr const char * kExchangeFlagsKey = "exchange_flags";
49+
constexpr const char * kIsInitiatorKey = "is_initiator";
50+
constexpr const char * kNeedsAckKey = "is_ack_requested";
51+
constexpr const char * kAckMsgKey = "acknowledged_msg_counter";
52+
constexpr const char * kPayloadDataKey = "payload_hex";
53+
constexpr const char * kPayloadSizeKey = "payload_size";
54+
constexpr const char * kDirectionKey = "direction";
55+
constexpr const char * kPeerAddress = "peer_address";
56+
57+
bool IsOutbound(const Json::Value & json)
58+
{
59+
VerifyOrReturnValue(json.isMember(kDirectionKey), false);
60+
return strcmp(json[kDirectionKey].asCString(), "outbound") == 0;
61+
}
62+
63+
bool IsInbound(const Json::Value & json)
64+
{
65+
VerifyOrReturnValue(json.isMember(kDirectionKey), false);
66+
return strcmp(json[kDirectionKey].asCString(), "inbound") == 0;
67+
}
68+
69+
} // namespace
5870

5971
using namespace logging;
6072

@@ -83,45 +95,8 @@ CHIP_ERROR TraceDecoder::ReadString(const char * str)
8395
str += strlen(jsonPrefix);
8496

8597
Json::Reader reader;
86-
87-
if (mJsonBuffer.empty())
88-
{
89-
VerifyOrReturnError(reader.parse(str, mJsonBuffer), CHIP_ERROR_INVALID_ARGUMENT);
90-
VerifyOrReturnError(mJsonBuffer.isMember(kPayloadDataKey) && mJsonBuffer.isMember(kPayloadSizeKey),
91-
CHIP_ERROR_INCORRECT_STATE);
92-
return CHIP_NO_ERROR;
93-
}
94-
9598
Json::Value json;
9699
VerifyOrReturnError(reader.parse(str, json), CHIP_ERROR_INVALID_ARGUMENT);
97-
98-
// If there is a source, then it means the previously saved payload is an encrypted to decode, otherwise
99-
// the previously saved payload is the non encrypted version, and the current decoded one is the encrypted version.
100-
if (mJsonBuffer.isMember(kSourceKey))
101-
{
102-
json[kPayloadEncryptedDataKey] = mJsonBuffer[kPayloadDataKey];
103-
json[kPayloadEncryptedSizeKey] = mJsonBuffer[kPayloadSizeKey];
104-
}
105-
else
106-
{
107-
auto data = json[kPayloadDataKey];
108-
auto size = json[kPayloadSizeKey];
109-
json[kPayloadDataKey] = mJsonBuffer[kPayloadDataKey];
110-
json[kPayloadSizeKey] = mJsonBuffer[kPayloadSizeKey];
111-
json[kPayloadEncryptedDataKey] = data;
112-
json[kPayloadEncryptedSizeKey] = size;
113-
}
114-
mJsonBuffer.removeMember(kPayloadDataKey);
115-
mJsonBuffer.removeMember(kPayloadSizeKey);
116-
117-
// If there is additional data in the previously saved json copy all of it.
118-
for (const auto & key : mJsonBuffer.getMemberNames())
119-
{
120-
json[key] = mJsonBuffer[key];
121-
mJsonBuffer.removeMember(key);
122-
}
123-
124-
VerifyOrReturnError(json.isMember(kSourceKey) || json.isMember(kDestinationKey), CHIP_ERROR_INCORRECT_STATE);
125100
VerifyOrReturnError(json.isMember(kProtocolIdKey), CHIP_ERROR_INCORRECT_STATE);
126101
VerifyOrReturnError(json.isMember(kProtocolCodeKey), CHIP_ERROR_INCORRECT_STATE);
127102

@@ -138,20 +113,19 @@ CHIP_ERROR TraceDecoder::LogJSON(Json::Value & json)
138113
return CHIP_NO_ERROR;
139114
}
140115

141-
if (!mOptions.mEnableMessageInitiator && json.isMember(kDestinationKey))
116+
if (!mOptions.mEnableMessageInitiator && IsOutbound(json))
142117
{
143118
return CHIP_NO_ERROR;
144119
}
145120

146-
if (!mOptions.mEnableMessageResponder && json.isMember(kSourceKey))
121+
if (!mOptions.mEnableMessageResponder && IsInbound(json))
147122
{
148123
return CHIP_NO_ERROR;
149124
}
150125

151-
bool isResponse = json.isMember(kSourceKey) ? true : false;
126+
bool isResponse = IsInbound(json);
152127
ReturnErrorOnFailure(LogAndConsumeProtocol(json));
153128
ReturnErrorOnFailure(MaybeLogAndConsumeHeaderFlags(json));
154-
ReturnErrorOnFailure(MaybeLogAndConsumeEncryptedPayload(json));
155129
ReturnErrorOnFailure(MaybeLogAndConsumePayload(json, isResponse));
156130
ReturnErrorOnFailure(MaybeLogAndConsumeOthers(json));
157131

@@ -168,26 +142,6 @@ CHIP_ERROR TraceDecoder::MaybeLogAndConsumeHeaderFlags(Json::Value & json)
168142
return CHIP_NO_ERROR;
169143
}
170144

171-
CHIP_ERROR TraceDecoder::MaybeLogAndConsumeEncryptedPayload(Json::Value & json)
172-
{
173-
if (mOptions.mEnableDataEncryptedPayload)
174-
{
175-
size_t size = static_cast<uint16_t>(json[kPayloadEncryptedSizeKey].asLargestUInt());
176-
if (size)
177-
{
178-
auto payload = json[kPayloadEncryptedDataKey].asString();
179-
auto bufferPtr = json[kPayloadEncryptedBufferPtrKey].asString();
180-
auto scopedIndent = ScopedLogIndentWithSize("Encrypted Payload", size);
181-
Log("data", payload.c_str());
182-
Log("buffer_ptr", bufferPtr.c_str());
183-
}
184-
}
185-
json.removeMember(kPayloadEncryptedSizeKey);
186-
json.removeMember(kPayloadEncryptedDataKey);
187-
json.removeMember(kPayloadEncryptedBufferPtrKey);
188-
return CHIP_NO_ERROR;
189-
}
190-
191145
CHIP_ERROR TraceDecoder::MaybeLogAndConsumeOthers(Json::Value & json)
192146
{
193147
std::vector<std::string> keys = json.getMemberNames();
@@ -218,8 +172,16 @@ CHIP_ERROR TraceDecoder::LogAndConsumeProtocol(Json::Value & json)
218172

219173
chip::StringBuilderBase builder(protocolInfo, sizeof(protocolInfo));
220174

221-
builder.Add(json.isMember(kSourceKey) ? "<< from " : ">> to ");
222-
builder.Add(json.isMember(kSourceKey) ? json[kSourceKey].asCString() : json[kDestinationKey].asCString());
175+
builder.Add(IsInbound(json) ? "<< from " : ">> to ");
176+
177+
if (json.isMember(kPeerAddress))
178+
{
179+
builder.Add(json[kPeerAddress].asCString());
180+
}
181+
else
182+
{
183+
builder.Add("UNKNOWN");
184+
}
223185

224186
builder.Add(" ");
225187
auto msgCounter = static_cast<uint32_t>(json[kMessageCounterKey].asLargestUInt());
@@ -258,11 +220,10 @@ CHIP_ERROR TraceDecoder::LogAndConsumeProtocol(Json::Value & json)
258220

259221
ChipLogProgress(DataManagement, "%s", builder.c_str());
260222

261-
json.removeMember(kSourceKey);
262-
json.removeMember(kDestinationKey);
263223
json.removeMember(kSessionIdKey);
264224
json.removeMember(kExchangeIdKey);
265225
json.removeMember(kMessageCounterKey);
226+
json.removeMember(kDirectionKey);
266227

267228
return CHIP_NO_ERROR;
268229
}

‎examples/common/tracing/TraceDecoder.h

+6-3
Original file line numberDiff line numberDiff line change
@@ -42,7 +42,12 @@ class TraceDecoder : public TraceStream
4242
{
4343
char buffer[2048] = {};
4444
snprintf(buffer, sizeof(buffer), " %s\t %s", tag.c_str(), data.c_str());
45-
ReadString(buffer);
45+
CHIP_ERROR err = ReadString(buffer);
46+
47+
if (err != CHIP_NO_ERROR)
48+
{
49+
ChipLogError(Automation, "Failed to add field: %" CHIP_ERROR_FORMAT, err.Format());
50+
}
4651
}
4752

4853
void FinishEvent() override {}
@@ -55,12 +60,10 @@ class TraceDecoder : public TraceStream
5560
CHIP_ERROR MaybeLogAndConsumeMessageFlags(Json::Value & value);
5661
CHIP_ERROR MaybeLogAndConsumeExchangeFlags(Json::Value & value);
5762
CHIP_ERROR MaybeLogAndConsumePayload(Json::Value & value, bool isResponse);
58-
CHIP_ERROR MaybeLogAndConsumeEncryptedPayload(Json::Value & value);
5963
CHIP_ERROR MaybeLogAndConsumeOthers(Json::Value & value);
6064

6165
private:
6266
TraceDecoderOptions mOptions;
63-
Json::Value mJsonBuffer;
6467
};
6568

6669
} // namespace trace

‎examples/common/tracing/TraceHandlers.cpp

+4-2
Original file line numberDiff line numberDiff line change
@@ -233,7 +233,9 @@ void SecureMessageSentHandler(const TraceSecureMessageSentData * eventData)
233233
return;
234234
}
235235

236-
std::string jsonBody = "{";
236+
std::string jsonBody = "{ \"direction\": \"outbound\", ";
237+
jsonBody += AsFirstJsonKey("peer_address", AsJsonString(eventData->peerAddress));
238+
jsonBody += ", ";
237239
jsonBody += PacketHeaderToJson(eventData->packetHeader);
238240
jsonBody += ", ";
239241
jsonBody += PayloadHeaderToJson(eventData->payloadHeader);
@@ -255,7 +257,7 @@ void SecureMessageReceivedHandler(const TraceSecureMessageReceivedData * eventDa
255257
return;
256258
}
257259

258-
std::string jsonBody = "{";
260+
std::string jsonBody = "{ \"direction\": \"inbound\", ";
259261
jsonBody += AsFirstJsonKey("peer_address", AsJsonString(eventData->peerAddress));
260262
jsonBody += ", ";
261263
jsonBody += PacketHeaderToJson(eventData->packetHeader);

‎src/transport/Session.h

-1
Original file line numberDiff line numberDiff line change
@@ -27,7 +27,6 @@
2727
#include <messaging/ReliableMessageProtocolConfig.h>
2828
#include <platform/LockTracker.h>
2929
#include <transport/SessionDelegate.h>
30-
#include <transport/raw/PeerAddress.h>
3130

3231
namespace chip {
3332
namespace Transport {

‎src/transport/SessionManager.cpp

+10-3
Original file line numberDiff line numberDiff line change
@@ -181,11 +181,13 @@ CHIP_ERROR SessionManager::PrepareMessage(const SessionHandle & sessionHandle, P
181181
return CHIP_ERROR_INTERNAL;
182182
}
183183

184+
PeerAddress destination_address = Transport::PeerAddress::Multicast(fabric->GetFabricId(), groupSession->GetGroupId());
185+
184186
// Trace before any encryption
185187
MATTER_LOG_MESSAGE_SEND(chip::Tracing::OutgoingMessageType::kGroupMessage, &payloadHeader, &packetHeader,
186188
chip::ByteSpan(message->Start(), message->TotalLength()));
187189

188-
CHIP_TRACE_MESSAGE_SENT(payloadHeader, packetHeader, message->Start(), message->TotalLength());
190+
CHIP_TRACE_MESSAGE_SENT(payloadHeader, packetHeader, destination_address, message->Start(), message->TotalLength());
189191

190192
Crypto::SymmetricKeyContext * keyContext =
191193
groups->GetKeyContext(groupSession->GetFabricIndex(), groupSession->GetGroupId());
@@ -219,10 +221,12 @@ CHIP_ERROR SessionManager::PrepareMessage(const SessionHandle & sessionHandle, P
219221
.SetSessionId(session->GetPeerSessionId()) //
220222
.SetSessionType(Header::SessionType::kUnicastSession);
221223

224+
PeerAddress destination_address = session->GetPeerAddress();
225+
222226
// Trace before any encryption
223227
MATTER_LOG_MESSAGE_SEND(chip::Tracing::OutgoingMessageType::kSecureSession, &payloadHeader, &packetHeader,
224228
chip::ByteSpan(message->Start(), message->TotalLength()));
225-
CHIP_TRACE_MESSAGE_SENT(payloadHeader, packetHeader, message->Start(), message->TotalLength());
229+
CHIP_TRACE_MESSAGE_SENT(payloadHeader, packetHeader, destination_address, message->Start(), message->TotalLength());
226230

227231
CryptoContext::NonceStorage nonce;
228232
NodeId sourceNodeId = session->GetLocalScopedNodeId().GetNodeId();
@@ -252,10 +256,13 @@ CHIP_ERROR SessionManager::PrepareMessage(const SessionHandle & sessionHandle, P
252256
break;
253257
}
254258

259+
auto unauthenticated = sessionHandle->AsUnauthenticatedSession();
260+
PeerAddress destination_address = unauthenticated->GetPeerAddress();
261+
255262
// Trace after all headers are settled.
256263
MATTER_LOG_MESSAGE_SEND(chip::Tracing::OutgoingMessageType::kUnauthenticated, &payloadHeader, &packetHeader,
257264
chip::ByteSpan(message->Start(), message->TotalLength()));
258-
CHIP_TRACE_MESSAGE_SENT(payloadHeader, packetHeader, message->Start(), message->TotalLength());
265+
CHIP_TRACE_MESSAGE_SENT(payloadHeader, packetHeader, destination_address, message->Start(), message->TotalLength());
259266

260267
ReturnErrorOnFailure(payloadHeader.EncodeBeforeData(message));
261268

‎src/transport/TraceMessage.h

+6-3
Original file line numberDiff line numberDiff line change
@@ -40,10 +40,10 @@
4040
#define _CHIP_TRACE_MESSAGE_INTERNAL(type, data, size) PW_TRACE_INSTANT_DATA(::chip::trace::kTraceMessageEvent, type, data, size);
4141
#endif // CHIP_CONFIG_TRANSPORT_TRACE_ENABLED && CHIP_CONFIG_TRANSPORT_PW_TRACE_ENABLED
4242

43-
#define CHIP_TRACE_MESSAGE_SENT(payloadHeader, packetHeader, data, dataLen) \
43+
#define CHIP_TRACE_MESSAGE_SENT(payloadHeader, packetHeader, peerAddress, data, dataLen) \
4444
do \
4545
{ \
46-
const ::chip::trace::TraceSecureMessageSentData _trace_data{ &payloadHeader, &packetHeader, data, dataLen }; \
46+
const ::chip::trace::TraceSecureMessageSentData _trace_data{ &payloadHeader, &packetHeader, &peerAddress, data, dataLen }; \
4747
_CHIP_TRACE_MESSAGE_INTERNAL(::chip::trace::kTraceMessageSentDataFormat, reinterpret_cast<const char *>(&_trace_data), \
4848
sizeof(_trace_data)); \
4949
} while (0)
@@ -58,14 +58,16 @@
5858
} while (0)
5959

6060
#else // CHIP_CONFIG_TRANSPORT_TRACE_ENABLED || CHIP_CONFIG_TRANSPORT_PW_TRACE_ENABLED
61-
#define CHIP_TRACE_MESSAGE_SENT(payloadHeader, packetHeader, data, dataLen) \
61+
#define CHIP_TRACE_MESSAGE_SENT(payloadHeader, packetHeader, peerAddress, data, dataLen) \
6262
do \
6363
{ \
64+
(void) peerAddress; \
6465
} while (0)
6566

6667
#define CHIP_TRACE_MESSAGE_RECEIVED(payloadHeader, packetHeader, session, peerAddress, data, dataLen) \
6768
do \
6869
{ \
70+
(void) peerAddress; \
6971
} while (0)
7072

7173
#endif // CHIP_CONFIG_TRANSPORT_TRACE_ENABLED || CHIP_CONFIG_TRANSPORT_PW_TRACE_ENABLED
@@ -81,6 +83,7 @@ struct TraceSecureMessageSentData
8183
{
8284
const PayloadHeader * payloadHeader;
8385
const PacketHeader * packetHeader;
86+
const Transport::PeerAddress * peerAddress;
8487
const uint8_t * packetPayload;
8588
size_t packetSize;
8689
};

0 commit comments

Comments
 (0)