espressif/openthread
1
0
Fork 0
mirror of https://github.com/espressif/openthread.git synced 2026-08-04 09:57:47 +00:00
Code Issues Packages Projects Releases Wiki Activity

[border-agent] improve logging and add session index (#12171)

Browse Source 
This commit introduces a session index tracked by each session
(`CoapDtlsSession`) to uniquely identify sessions in log messages.
The `Manager` now maintains a counter to assign a new index to each
session upon allocation.

Logs are added to track the lifecycle of a session (allocation,
connection, disconnection, deletion, and timeout), with each event
including the session's unique index.

A new templated helper, `Log<kUri>()`, is added to standardize logging
for TMF messages, including response handling. The session index is
included in such logs to provide clearer insight into the processing
of specific TMF commands by Border Agent sessions.
This commit is contained in:
Abtin Keshavarzian
2025-11-20 21:52:55 -08:00
committed by GitHub
parent e5b159a20f
commit 9483553c44
2 changed files with 130 additions and 15 deletions
Download Patch File Download Diff File Expand all files Collapse all files
src/core/meshcop/border_agent.cpp
+108 -15
View File
@@ -56,6 +56,7 @@ Manager::Manager(Instance &aInstance)
: InstanceLocator(aInstance)
, mEnabled(true)
, mIsRunning(false)
, mSessionIndex(0)
, mDtlsTransport(aInstance, kNoLinkSecurity)
, mCommissionerSession(nullptr)
, mCommissionerUdpReceiver(HandleUdpReceive, this)
@@ -249,6 +250,8 @@ void Manager::HandleRemoveSession(SecureSession &aSession)
{
CoapDtlsSession &coapSession = static_cast<CoapDtlsSession &>(aSession);
LogInfo("Deleting session %u", coapSession.GetIndex());
coapSession.Cleanup();
coapSession.Free();
}
@@ -302,7 +305,7 @@ void Manager::HandleCommissionerPetitionAccepted(CoapDtlsSession &aSession, uint
IgnoreError(Get<Ip6::Udp>().AddReceiver(mCommissionerUdpReceiver));
LogInfo("Commissioner accepted - SessionId:%u ALOC:%s", aSessionId,
LogInfo("Session %u accepted as active commissioner - Id:0x%04x ALOC:%s", aSession.GetIndex(), aSessionId,
mCommissionerAloc.GetAddress().ToString().AsCString());
#if OPENTHREAD_CONFIG_BORDER_AGENT_EPHEMERAL_KEY_ENABLE
@@ -321,7 +324,7 @@ void Manager::RevokeRoleIfActiveCommissioner(CoapDtlsSession &aSession)
{
VerifyOrExit(IsCommissionerSession(aSession));
LogInfo("Commissioner role revoked");
LogInfo("Revoked active commissioner role from session %u", aSession.GetIndex());
IgnoreError(Get<Ip6::Udp>().RemoveReceiver(mCommissionerUdpReceiver));
Get<ThreadNetif>().RemoveUnicastAddress(mCommissionerAloc);
@@ -361,6 +364,8 @@ template <> void Manager::HandleTmf<kUriRelayRx>(Coap::Message &aMessage, const
VerifyOrExit(aMessage.IsNonConfirmablePostRequest());
LogInfo("Received %s from %s", UriToString<kUriRelayRx>(), aMessageInfo.GetPeerAddr().ToString().AsCString());
VerifyOrExit(mCommissionerSession != nullptr);
mCommissionerSession->ForwardUdpRelayToCommissioner(aMessage);
@@ -505,9 +510,12 @@ Manager::CoapDtlsSession::CoapDtlsSession(Instance &aInstance, Dtls::Transport &
: Coap::SecureSession(aInstance, aDtlsTransport)
, mTimer(aInstance, HandleTimer, this)
, mAllocationTime(aInstance.Get<Uptime>().GetUptime())
, mIndex(aInstance.Get<Manager>().GetNextSessionIndex())
{
SetResourceHandler(&HandleResource);
SetConnectCallback(&HandleConnected, this);
LogInfo("Allocating session %u", mIndex);
}
Error Manager::CoapDtlsSession::SendMessage(OwnedPtr<Coap::Message> aMessage)
@@ -558,6 +566,7 @@ bool Manager::CoapDtlsSession::HandleResource(const char *aUriPath,
switch (uri)
{
case kUriCommissionerPetition:
Log<kUriCommissionerPetition>(kReceive);
IgnoreError(ForwardToLeader(aMessage, aMessageInfo, kUriLeaderPetition));
break;
case kUriCommissionerKeepAlive:
@@ -591,13 +600,13 @@ void Manager::CoapDtlsSession::HandleConnected(ConnectEvent aEvent)
{
if (aEvent == kConnected)
{
LogInfo("SecureSession connected");
LogInfo("Session %u connected", mIndex);
mTimer.Start(kKeepAliveTimeout);
Get<Manager>().HandleSessionConnected(*this);
}
else
{
LogInfo("SecureSession disconnected");
LogInfo("Session %u disconnected", mIndex);
Get<Manager>().HandleSessionDisconnected(*this, aEvent);
}
}
@@ -607,6 +616,8 @@ void Manager::CoapDtlsSession::HandleTmfCommissionerKeepAlive(Coap::Message
{
VerifyOrExit(IsActiveCommissioner());
Log<kUriCommissionerKeepAlive>(kReceive);
SuccessOrExit(ForwardToLeader(aMessage, aMessageInfo, kUriLeaderKeepAlive));
mTimer.Start(kKeepAliveTimeout);
#if OPENTHREAD_CONFIG_BORDER_AGENT_EPHEMERAL_KEY_ENABLE && OPENTHREAD_CONFIG_HISTORY_TRACKER_ENABLE
@@ -664,7 +675,17 @@ Error Manager::CoapDtlsSession::ForwardToLeader(const Coap::Message &aMessage
mForwardContexts.Push(*forwardContext.Release());
LogInfo("Forwarded request to leader on %s", PathForUri(aUri));
switch (aUri)
{
case kUriLeaderPetition:
Log<kUriLeaderPetition>(kForward, " to leader");
break;
case kUriLeaderKeepAlive:
Log<kUriLeaderKeepAlive>(kForward, " to leader");
break;
default:
break;
}
exit:
LogWarnOnError(error, "forward to leader");
@@ -698,6 +719,18 @@ void Manager::CoapDtlsSession::HandleLeaderResponseToFwdTmf(const ForwardContext
IgnoreError(mForwardContexts.Remove(aForwardContext));
switch (aForwardContext.mUri)
{
case kUriLeaderPetition:
Log<kUriLeaderPetition>(kReceive, " response from leader");
break;
case kUriLeaderKeepAlive:
Log<kUriLeaderKeepAlive>(kReceive, " response from leader");
break;
default:
break;
}
SuccessOrExit(error = aResult);
forwardMessage.Reset(NewPriorityMessage());
@@ -745,7 +778,23 @@ void Manager::CoapDtlsSession::HandleLeaderResponseToFwdTmf(const ForwardContext
exit:
if (error != kErrorNone)
{
LogWarn("Commissioner request failed: %s", ErrorToString(error));
#if OT_SHOULD_LOG_AT(OT_LOG_LEVEL_WARN)
const char *uriString = "Unknown";
switch (aForwardContext.mUri)
{
case kUriLeaderPetition:
uriString = UriToString<kUriLeaderPetition>();
break;
case kUriLeaderKeepAlive:
uriString = UriToString<kUriLeaderKeepAlive>();
break;
default:
break;
}
LogWarn("Forwarded %s failed - session %u, error:%s", uriString, mIndex, ErrorToString(error));
#endif
SendErrorMessage(error, aForwardContext.mToken, aForwardContext.mTokenLength);
}
@@ -781,10 +830,10 @@ void Manager::CoapDtlsSession::ForwardUdpProxyToCommissioner(const Message
SuccessOrExit(error = SendMessage(message.PassOwnership()));
LogInfo("Sent ProxyRx (c/ur) to commissioner");
Log<kUriProxyRx>(kForward);
exit:
LogWarnOnError(error, "send ProxyRx (c/ur)");
LogWarnOnError(error, "forward UDP proxy");
}
void Manager::CoapDtlsSession::ForwardUdpRelayToCommissioner(const Message &aMessage)
@@ -797,10 +846,10 @@ void Manager::CoapDtlsSession::ForwardUdpRelayToCommissioner(const Message &aMes
SuccessOrExit(error = ForwardToCommissioner(forwardMessage.PassOwnership(), aMessage));
LogInfo("Sent RelayRx (c/rx) to commissioner");
Log<kUriRelayRx>(kForward);
exit:
LogWarnOnError(error, "send RelayRx (c/rx)");
LogWarnOnError(error, "forward UDP relay");
}
Error Manager::CoapDtlsSession::ForwardToCommissioner(OwnedPtr<Coap::Message> aForwardMessage, const Message &aMessage)
@@ -845,6 +894,8 @@ void Manager::CoapDtlsSession::HandleTmfProxyTx(Coap::Message &aMessage)
OffsetRange offsetRange;
UdpEncapsulationTlvHeader udpEncapHeader;
Log<kUriProxyTx>(kReceive);
VerifyOrExit(IsActiveCommissioner(), error = kErrorInvalidState);
SuccessOrExit(error = Tlv::FindTlvValueOffsetRange(aMessage, Tlv::kUdpEncapsulation, offsetRange));
@@ -869,7 +920,7 @@ void Manager::CoapDtlsSession::HandleTmfProxyTx(Coap::Message &aMessage)
SuccessOrExit(error = Get<Ip6::Udp>().SendDatagram(*message, messageInfo));
message.Release();
LogInfo("Proxy transmit sent to %s", messageInfo.GetPeerAddr().ToString().AsCString());
LogInfo("Sent proxy UDP to %s", messageInfo.GetPeerAddr().ToString().AsCString());
exit:
LogWarnOnError(error, "send proxy stream");
@@ -887,6 +938,8 @@ void Manager::CoapDtlsSession::HandleTmfRelayTx(Coap::Message &aMessage)
VerifyOrExit(IsActiveCommissioner(), error = kErrorInvalidState);
Log<kUriRelayTx>(kReceive);
SuccessOrExit(error = Tlv::Find<JoinerRouterLocatorTlv>(aMessage, joinerRouterRloc));
message.Reset(Get<Tmf::Agent>().NewPriorityNonConfirmablePostMessage(kUriRelayTx));
@@ -902,10 +955,10 @@ void Manager::CoapDtlsSession::HandleTmfRelayTx(Coap::Message &aMessage)
SuccessOrExit(error = Get<Tmf::Agent>().SendMessage(*message, messageInfo));
message.Release();
LogInfo("Sent to joiner router request on RelayTx (c/tx)");
LogInfo("Forward %s to joiner router 0x%04x", UriToString<kUriRelayTx>(), joinerRouterRloc);
exit:
LogWarnOnError(error, "send to joiner router request RelayTx (c/tx)");
LogWarnOnError(error, "forward to joiner router");
}
void Manager::CoapDtlsSession::HandleTmfDatasetGet(Coap::Message &aMessage, Uri aUri)
@@ -920,6 +973,7 @@ void Manager::CoapDtlsSession::HandleTmfDatasetGet(Coap::Message &aMessage, Uri
switch (aUri)
{
case kUriActiveGet:
Log<kUriActiveGet>(kReceive);
response.Reset(
Get<ActiveDatasetManager>().ProcessGetRequest(aMessage, DatasetManager::kIgnoreSecurityPolicyFlags));
Get<Manager>().mCounters.mMgmtActiveGets++;
@@ -932,6 +986,7 @@ void Manager::CoapDtlsSession::HandleTmfDatasetGet(Coap::Message &aMessage, Uri
break;
case kUriPendingGet:
Log<kUriPendingGet>(kReceive);
response.Reset(
Get<PendingDatasetManager>().ProcessGetRequest(aMessage, DatasetManager::kIgnoreSecurityPolicyFlags));
Get<Manager>().mCounters.mMgmtPendingGets++;
@@ -944,6 +999,7 @@ void Manager::CoapDtlsSession::HandleTmfDatasetGet(Coap::Message &aMessage, Uri
break;
case kUriCommissionerGet:
Log<kUriCommissionerGet>(kReceive);
response.Reset(Get<NetworkData::Leader>().ProcessCommissionerGetRequest(aMessage));
break;
@@ -955,7 +1011,20 @@ void Manager::CoapDtlsSession::HandleTmfDatasetGet(Coap::Message &aMessage, Uri
SuccessOrExit(error = SendMessage(response.PassOwnership()));
LogInfo("Sent %s response to non-active commissioner", PathForUri(aUri));
switch (aUri)
{
case kUriActiveGet:
Log<kUriActiveGet>(kSend, " response");
break;
case kUriPendingGet:
Log<kUriPendingGet>(kSend, " response");
break;
case kUriCommissionerGet:
Log<kUriCommissionerGet>(kSend, " response");
break;
default:
break;
}
exit:
LogWarnOnError(error, "send Active/Pending/CommissionerGet response");
@@ -970,11 +1039,35 @@ void Manager::CoapDtlsSession::HandleTimer(void)
{
if (IsConnected())
{
LogInfo("Session timed out - disconnecting");
LogInfo("Session %u timed out - disconnecting", mIndex);
DisconnectTimeout();
}
}
#if OT_SHOULD_LOG_AT(OT_LOG_LEVEL_INFO)
void Manager::CoapDtlsSession::LogUri(Action aAction, const char *aUriString, const char *aTxt)
{
static const char *const kActionStrings[] = {
"Receive", // kReceive
"Send", // kSend
"Forward", // kForward,
};
struct EnumChecker
{
InitEnumValidatorCounter();
ValidateNextEnum(kReceive);
ValidateNextEnum(kSend);
ValidateNextEnum(kForward);
};
LogInfo("%s %s%s - session %u", kActionStrings[aAction], aUriString, aTxt, mIndex);
}
#endif
//----------------------------------------------------------------------------------------------------------------------
// `Manager::CoapDtlsSession::ForwardContext`
src/core/meshcop/border_agent.hpp
+22
View File
@@ -47,6 +47,7 @@
#include "common/heap_allocatable.hpp"
#include "common/linked_list.hpp"
#include "common/locator.hpp"
#include "common/log.hpp"
#include "common/non_copyable.hpp"
#include "common/notifier.hpp"
#include "common/owned_ptr.hpp"
@@ -261,8 +262,16 @@ private:
void Cleanup(void);
bool IsActiveCommissioner(void) const;
uint64_t GetAllocationTime(void) const { return mAllocationTime; }
uint16_t GetIndex(void) const { return mIndex; }
private:
enum Action : uint8_t
{
kReceive,
kSend,
kForward,
};
struct ForwardContext : public ot::LinkedListEntry<ForwardContext>,
public Heap::Allocatable<ForwardContext>,
private ot::NonCopyable
@@ -303,9 +312,20 @@ private:
static void HandleTimer(Timer &aTimer);
void HandleTimer(void);
#if OT_SHOULD_LOG_AT(OT_LOG_LEVEL_INFO)
void LogUri(Action aAction, const char *aUriString, const char *aTxt);
template <Uri kUri> void Log(Action aAction) { Log<kUri>(aAction, ""); }
template <Uri kUri> void Log(Action aAction, const char *aTxt) { LogUri(aAction, UriToString<kUri>(), aTxt); }
#else
template <Uri kUri> void Log(Action) {}
template <Uri kUri> void Log(Action, const char *) {}
#endif
LinkedList<ForwardContext> mForwardContexts;
TimerMilliContext mTimer;
uint64_t mAllocationTime;
uint16_t mIndex;
};
void UpdateState(void);
@@ -323,6 +343,7 @@ private:
static void HandleRemoveSession(void *aContext, SecureSession &aSession);
void HandleRemoveSession(SecureSession &aSession);
uint16_t GetNextSessionIndex(void) { return ++mSessionIndex; }
const Ip6::Address &GetCommissionerAloc(void) const { return mCommissionerAloc.GetAddress(); }
CoapDtlsSession *GetCommissionerSession(void) { return mCommissionerSession; }
@@ -356,6 +377,7 @@ private:
bool mEnabled;
bool mIsRunning;
uint16_t mSessionIndex;
Dtls::Transport mDtlsTransport;
CoapDtlsSession *mCommissionerSession;
Ip6::Udp::Receiver mCommissionerUdpReceiver;