Skip to content

Commit

Permalink
trace: Add tracing for prepared secure messages (#16565)
Browse files Browse the repository at this point in the history 
- Add new traces for the prepared messages for send and receive.
- Add handlers to pack the data into json.

Note: This is only enabled when CHIP_CONFIG_TRANSPORT_TRACE is
      enabled, otherwise this is a no-op.
  • Loading branch information
rgoliver authored Mar 24, 2022
1 parent 4d6858b commit dad6375
Show file tree
Hide file tree
Showing 3 changed files with 96 additions and 22 deletions.
72 changes: 55 additions & 17 deletions examples/common/tracing/TraceHandlers.cpp
View file
Original file line number Diff line number Diff line change
Expand Up @@ -214,9 +214,27 @@ std::string PayloadHeaderToJson(const PayloadHeader * payloadHeader)
return jsonBody;
}

bool SecureMessageSentHandler(const TraceEventFields & eventFields, TraceHandlerContext * context)
std::string PreparedSecureMessageDataToJson(const TracePreparedSecureMessageData * data, const std::string & peerAddressKey)
{
if (eventFields.dataSize != sizeof(TraceSecureMessageSentData))
const System::PacketBuffer * packetBuffer = data->packetBuffer->operator->();
std::string jsonBody = "{";
jsonBody += AsFirstJsonKey(peerAddressKey, AsJsonString(data->peerAddress));
jsonBody += ", ";
jsonBody += AsFirstJsonKey("payload_size", std::to_string(packetBuffer->DataLength()));
jsonBody += ", ";
jsonBody += AsFirstJsonKey("payload_hex", AsJsonHexString(packetBuffer->Start(), packetBuffer->DataLength()));
jsonBody += ", ";
jsonBody += AsFirstJsonKey("buffer_ptr", std::to_string(reinterpret_cast<std::uintptr_t>(packetBuffer)));
jsonBody += "}";

return jsonBody;
}

bool SecureMessageSentHandler(const TraceEventFields & eventFields, void * context)
{
TraceHandlerContext * ourContext = reinterpret_cast<TraceHandlerContext *>(context);
if ((std::string{ eventFields.dataFormat } != kTraceMessageSentDataFormat) ||
(eventFields.dataSize != sizeof(TraceSecureMessageSentData)))
{
return false;
}
Expand All @@ -232,17 +250,19 @@ bool SecureMessageSentHandler(const TraceEventFields & eventFields, TraceHandler
jsonBody += AsFirstJsonKey("payload_hex", AsJsonHexString(eventData->packetPayload, eventData->packetSize));
jsonBody += "}";

TraceOutput * sink = context->sink;
TraceOutput * sink = ourContext->sink;
sink->StartEvent(std::string{ kTraceMessageEvent } + "." + kTraceMessageSentDataFormat);
sink->AddField("json", jsonBody);
sink->FinishEvent();

return true;
}

bool SecureMessageReceivedHandler(const TraceEventFields & eventFields, TraceHandlerContext * context)
bool SecureMessageReceivedHandler(const TraceEventFields & eventFields, void * context)
{
if (eventFields.dataSize != sizeof(TraceSecureMessageReceivedData))
TraceHandlerContext * ourContext = reinterpret_cast<TraceHandlerContext *>(context);
if ((std::string{ eventFields.dataFormat } != kTraceMessageReceivedDataFormat) ||
(eventFields.dataSize != sizeof(TraceSecureMessageReceivedData)))
{
return false;
}
Expand All @@ -261,7 +281,7 @@ bool SecureMessageReceivedHandler(const TraceEventFields & eventFields, TraceHan
jsonBody += AsFirstJsonKey("payload_hex", AsJsonHexString(eventData->packetPayload, eventData->packetSize));
jsonBody += "}";

TraceOutput * sink = context->sink;
TraceOutput * sink = ourContext->sink;
sink->StartEvent(std::string{ kTraceMessageEvent } + "." + kTraceMessageReceivedDataFormat);
sink->AddField("json", jsonBody);
sink->FinishEvent();
Expand All @@ -271,25 +291,40 @@ bool SecureMessageReceivedHandler(const TraceEventFields & eventFields, TraceHan
return true;
}

// TODO: Framework this into a registry of handlers for different message types.
bool TraceDefaultHandler(const TraceEventFields & eventFields, void * context)
bool PreparedMessageSentHandler(const TraceEventFields & eventFields, void * context)
{
TraceHandlerContext * ourContext = reinterpret_cast<TraceHandlerContext *>(context);
if (ourContext == nullptr)
if ((std::string{ eventFields.dataFormat } != kTracePreparedMessageSentDataFormat) ||
(eventFields.dataSize != sizeof(TracePreparedSecureMessageData)))
{
return false;
}

if (std::string{ eventFields.dataFormat } == kTraceMessageSentDataFormat)
{
return SecureMessageSentHandler(eventFields, ourContext);
}
else if (std::string{ eventFields.dataFormat } == kTraceMessageReceivedDataFormat)
const auto * eventData = reinterpret_cast<const TracePreparedSecureMessageData *>(eventFields.dataBuffer);
TraceOutput * sink = ourContext->sink;
sink->StartEvent(std::string{ kTraceMessageEvent } + "." + kTracePreparedMessageSentDataFormat);
sink->AddField("json", PreparedSecureMessageDataToJson(eventData, "destination"));
sink->FinishEvent();

return true;
}

bool PreparedMessageReceivedHandler(const TraceEventFields & eventFields, void * context)
{
TraceHandlerContext * ourContext = reinterpret_cast<TraceHandlerContext *>(context);
if ((std::string{ eventFields.dataFormat } != kTracePreparedMessageReceivedDataFormat) ||
(eventFields.dataSize != sizeof(TracePreparedSecureMessageData)))
{
return SecureMessageReceivedHandler(eventFields, ourContext);
return false;
}

return false;
const auto * eventData = reinterpret_cast<const TracePreparedSecureMessageData *>(eventFields.dataBuffer);
TraceOutput * sink = ourContext->sink;
sink->StartEvent(std::string{ kTraceMessageEvent } + "." + kTracePreparedMessageReceivedDataFormat);
sink->AddField("json", PreparedSecureMessageDataToJson(eventData, "source"));
sink->FinishEvent();

return true;
}

} // namespace
Expand All @@ -302,7 +337,10 @@ void SetTraceStream(TraceStream * stream)
void InitTrace()
{
void * context = &gTraceHandlerContext;
RegisterTraceHandler(TraceDefaultHandler, context);
RegisterTraceHandler(SecureMessageSentHandler, context);
RegisterTraceHandler(SecureMessageReceivedHandler, context);
RegisterTraceHandler(PreparedMessageSentHandler, context);
RegisterTraceHandler(PreparedMessageReceivedHandler, context);
}

void DeInitTrace()
Expand Down
2 changes: 2 additions & 0 deletions src/transport/SessionManager.cpp
View file
Original file line number Diff line number Diff line change
Expand Up @@ -318,6 +318,7 @@ CHIP_ERROR SessionManager::SendPreparedMessage(const SessionHandle & sessionHand

if (mTransportMgr != nullptr)
{
CHIP_TRACE_PREPARED_MESSAGE_SENT(destination, &msgBuf);
return mTransportMgr->SendMessage(*destination, std::move(msgBuf));
}

Expand Down Expand Up @@ -414,6 +415,7 @@ void SessionManager::CancelExpiryTimer()

void SessionManager::OnMessageReceived(const PeerAddress & peerAddress, System::PacketBufferHandle && msg)
{
CHIP_TRACE_PREPARED_MESSAGE_RECEIVED(&peerAddress, &msg);
PacketHeader packetHeader;

ReturnOnFailure(packetHeader.DecodeAndConsume(msg));
Expand Down
44 changes: 39 additions & 5 deletions src/transport/TraceMessage.h
View file
Original file line number Diff line number Diff line change
Expand Up @@ -19,6 +19,7 @@
#pragma once

#include <core/CHIPBuildConfig.h>
#include <system/SystemPacketBuffer.h>
#include <transport/Session.h>
#include <transport/raw/MessageHeader.h>
#include <transport/raw/PeerAddress.h>
Expand All @@ -30,7 +31,7 @@
do \
{ \
const ::chip::trace::TraceSecureMessageSentData _trace_data{ &payloadHeader, &packetHeader, data, dataLen }; \
PW_TRACE_INSTANT_DATA("SecureMsg", ::chip::trace::kTraceMessageSentDataFormat, \
PW_TRACE_INSTANT_DATA(::chip::trace::kTraceMessageEvent, ::chip::trace::kTraceMessageSentDataFormat, \
reinterpret_cast<const void *>(&_trace_data), sizeof(_trace_data)); \
} while (0)

Expand All @@ -39,7 +40,23 @@
{ \
const ::chip::trace::TraceSecureMessageReceivedData _trace_data{ &payloadHeader, &packetHeader, session, \
&peerAddress, data, dataLen }; \
PW_TRACE_INSTANT_DATA("SecureMsg", ::chip::trace::kTraceMessageReceivedDataFormat, \
PW_TRACE_INSTANT_DATA(::chip::trace::kTraceMessageEvent, ::chip::trace::kTraceMessageReceivedDataFormat, \
reinterpret_cast<const void *>(&_trace_data), sizeof(_trace_data)); \
} while (0)

#define CHIP_TRACE_PREPARED_MESSAGE_SENT(destination, packetBuffer) \
do \
{ \
const ::chip::trace::TracePreparedSecureMessageData _trace_data{ destination, packetBuffer }; \
PW_TRACE_INSTANT_DATA(::chip::trace::kTraceMessageEvent, ::chip::trace::kTracePreparedMessageSentDataFormat, \
reinterpret_cast<const void *>(&_trace_data), sizeof(_trace_data)); \
} while (0)

#define CHIP_TRACE_PREPARED_MESSAGE_RECEIVED(source, packetBuffer) \
do \
{ \
const ::chip::trace::TracePreparedSecureMessageData _trace_data{ source, packetBuffer }; \
PW_TRACE_INSTANT_DATA(::chip::trace::kTraceMessageEvent, ::chip::trace::kTracePreparedMessageReceivedDataFormat, \
reinterpret_cast<const void *>(&_trace_data), sizeof(_trace_data)); \
} while (0)

Expand All @@ -54,14 +71,25 @@
{ \
} while (0)

#define CHIP_TRACE_PREPARED_MESSAGE_SENT(destination, packetBuffer) \
do \
{ \
} while (0)

#define CHIP_TRACE_PREPARED_MESSAGE_RECEIVED(source, packetBuffer) \
do \
{ \
} while (0)
#endif // CHIP_CONFIG_TRANSPORT_TRACE_ENABLED

namespace chip {
namespace trace {

constexpr const char * kTraceMessageEvent = "SecureMsg";
constexpr const char * kTraceMessageSentDataFormat = "SecMsgSent";
constexpr const char * kTraceMessageReceivedDataFormat = "SecMsgReceived";
constexpr const char * kTraceMessageEvent = "SecureMsg";
constexpr const char * kTraceMessageSentDataFormat = "SecMsgSent";
constexpr const char * kTraceMessageReceivedDataFormat = "SecMsgReceived";
constexpr const char * kTracePreparedMessageSentDataFormat = "PreparedMsgSent";
constexpr const char * kTracePreparedMessageReceivedDataFormat = "PreparedMsgReceived";

struct TraceSecureMessageSentData
{
Expand All @@ -81,5 +109,11 @@ struct TraceSecureMessageReceivedData
size_t packetSize;
};

struct TracePreparedSecureMessageData
{
const Transport::PeerAddress * peerAddress;
const System::PacketBufferHandle * packetBuffer;
};

} // namespace trace
} // namespace chip

0 comments on commit dad6375

Please sign in to comment.