Skip to content

Commit d58876e

Browse files
leonardmghleonardmgh
committed
Add loogging of nodeID patch
1 parent e961bd3 commit d58876e

File tree

1 file changed

+171
-0
lines changed

1 file changed

+171
-0
lines changed

‎0010-Log-nodeID-in-exchange-context.patch

+171
Original file line numberDiff line numberDiff line change
@@ -0,0 +1,171 @@
1+
From cdaea7e190ebf60a701da629a98aa0e9927c74d1 Mon Sep 17 00:00:00 2001
2+
From: Leonard Hansen <leonard@hansen-net.eu>
3+
Date: Mon, 4 Mar 2024 00:28:15 +0100
4+
Subject: [PATCH] Log nodeID in exchange context
5+
6+
---
7+
src/lib/support/logging/TextOnlyLogging.h | 4 ++++
8+
src/messaging/ReliableMessageContext.cpp | 24 +++++++++++------------
9+
src/messaging/ReliableMessageMgr.cpp | 24 +++++++++++------------
10+
3 files changed, 28 insertions(+), 24 deletions(-)
11+
12+
diff --git a/src/lib/support/logging/TextOnlyLogging.h b/src/lib/support/logging/TextOnlyLogging.h
13+
index d6b22f7c6c..1c5ece1b77 100644
14+
--- a/src/lib/support/logging/TextOnlyLogging.h
15+
+++ b/src/lib/support/logging/TextOnlyLogging.h
16+
@@ -284,6 +284,10 @@ using LogRedirectCallback_t = void (*)(const char * module, uint8_t category, co
17+
#define ChipLogValueExchangeIdFromReceivedHeader(payloadHeader) \
18+
ChipLogValueExchangeId((payloadHeader).GetExchangeID(), !(payloadHeader).IsInitiator())
19+
20+
+#define ChipLogFormatExchangeExtended ChipLogFormatExchangeId " with NodeID " "%" PRIu64
21+
+#define ChipLogValueExchangeExtended(ec) ChipLogValueExchange(ec), \
22+
+ (ec)->HasSessionHandle() ? (ec)->GetSessionHandle()->GetSubjectDescriptor().subject : kUndefinedNodeId
23+
+
24+
/**
25+
* Logging helpers for protocol ids. A protocol id is a (vendor-id,
26+
* protocol-id) pair.
27+
diff --git a/src/messaging/ReliableMessageContext.cpp b/src/messaging/ReliableMessageContext.cpp
28+
index 30f00a6781..7424b59ab5 100644
29+
--- a/src/messaging/ReliableMessageContext.cpp
30+
+++ b/src/messaging/ReliableMessageContext.cpp
31+
@@ -72,8 +72,8 @@ CHIP_ERROR ReliableMessageContext::FlushAcks()
32+
{
33+
ChipLogDetail(ExchangeManager,
34+
"Flushed pending ack for MessageCounter:" ChipLogFormatMessageCounter
35+
- " on exchange " ChipLogFormatExchange,
36+
- mPendingPeerAckMessageCounter, ChipLogValueExchange(GetExchangeContext()));
37+
+ " on exchange " ChipLogFormatExchangeExtended,
38+
+ mPendingPeerAckMessageCounter, ChipLogValueExchangeExtended(GetExchangeContext()));
39+
}
40+
}
41+
42+
@@ -101,8 +101,8 @@ void ReliableMessageContext::HandleRcvdAck(uint32_t ackMessageCounter)
43+
// This can happen quite easily due to a packet with a piggyback ack
44+
// being lost and retransmitted.
45+
ChipLogDetail(ExchangeManager,
46+
- "CHIP MessageCounter:" ChipLogFormatMessageCounter " not in RetransTable on exchange " ChipLogFormatExchange,
47+
- ackMessageCounter, ChipLogValueExchange(GetExchangeContext()));
48+
+ "CHIP MessageCounter:" ChipLogFormatMessageCounter " not in RetransTable on exchange " ChipLogFormatExchangeExtended,
49+
+ ackMessageCounter, ChipLogValueExchangeExtended(GetExchangeContext()));
50+
}
51+
}
52+
53+
@@ -125,8 +125,8 @@ CHIP_ERROR ReliableMessageContext::HandleNeedsAckInner(uint32_t messageCounter,
54+
{
55+
ChipLogDetail(ExchangeManager,
56+
"Forcing tx of solitary ack for duplicate MessageCounter:" ChipLogFormatMessageCounter
57+
- " on exchange " ChipLogFormatExchange,
58+
- messageCounter, ChipLogValueExchange(GetExchangeContext()));
59+
+ " on exchange " ChipLogFormatExchangeExtended,
60+
+ messageCounter, ChipLogValueExchangeExtended(GetExchangeContext()));
61+
62+
bool wasAckPending = IsAckPending() && mPendingPeerAckMessageCounter != messageCounter;
63+
64+
@@ -162,8 +162,8 @@ CHIP_ERROR ReliableMessageContext::HandleNeedsAckInner(uint32_t messageCounter,
65+
{
66+
ChipLogDetail(ExchangeManager,
67+
"Pending ack queue full; forcing tx of solitary ack for MessageCounter:" ChipLogFormatMessageCounter
68+
- " on exchange " ChipLogFormatExchange,
69+
- mPendingPeerAckMessageCounter, ChipLogValueExchange(GetExchangeContext()));
70+
+ " on exchange " ChipLogFormatExchangeExtended,
71+
+ mPendingPeerAckMessageCounter, ChipLogValueExchangeExtended(GetExchangeContext()));
72+
// Send the Ack for the currently pending Ack in a SecureChannel::StandaloneAck message.
73+
ReturnErrorOnFailure(SendStandaloneAckMessage());
74+
}
75+
@@ -190,16 +190,16 @@ CHIP_ERROR ReliableMessageContext::SendStandaloneAckMessage()
76+
{
77+
ChipLogError(ExchangeManager,
78+
"Non-crit err %" CHIP_ERROR_FORMAT " sending solitary ack for MessageCounter:" ChipLogFormatMessageCounter
79+
- " on exchange " ChipLogFormatExchange,
80+
- err.Format(), mPendingPeerAckMessageCounter, ChipLogValueExchange(GetExchangeContext()));
81+
+ " on exchange " ChipLogFormatExchangeExtended,
82+
+ err.Format(), mPendingPeerAckMessageCounter, ChipLogValueExchangeExtended(GetExchangeContext()));
83+
return CHIP_NO_ERROR;
84+
}
85+
if (err != CHIP_NO_ERROR)
86+
{
87+
ChipLogError(ExchangeManager,
88+
"Failed to send Solitary ack for MessageCounter:" ChipLogFormatMessageCounter
89+
- " on exchange " ChipLogFormatExchange ":%" CHIP_ERROR_FORMAT,
90+
- mPendingPeerAckMessageCounter, ChipLogValueExchange(GetExchangeContext()), err.Format());
91+
+ " on exchange " ChipLogFormatExchangeExtended ":%" CHIP_ERROR_FORMAT,
92+
+ mPendingPeerAckMessageCounter, ChipLogValueExchangeExtended(GetExchangeContext()), err.Format());
93+
}
94+
95+
return err;
96+
diff --git a/src/messaging/ReliableMessageMgr.cpp b/src/messaging/ReliableMessageMgr.cpp
97+
index e22bd4db24..d6d41cd1bf 100644
98+
--- a/src/messaging/ReliableMessageMgr.cpp
99+
+++ b/src/messaging/ReliableMessageMgr.cpp
100+
@@ -89,8 +89,8 @@ void ReliableMessageMgr::TicklessDebugDumpRetransTable(const char * log)
101+
102+
mRetransTable.ForEachActiveObject([&](auto * entry) {
103+
ChipLogDetail(ExchangeManager,
104+
- "EC:" ChipLogFormatExchange " MessageCounter:" ChipLogFormatMessageCounter " NextRetransTimeCtr:%" PRIu64,
105+
- ChipLogValueExchange(&entry->ec.Get()), entry->retainedBuf.GetMessageCounter(),
106+
+ "EC:" ChipLogFormatExchangeExtended " MessageCounter:" ChipLogFormatMessageCounter " NextRetransTimeCtr:%" PRIu64,
107+
+ ChipLogValueExchangeExtended(&entry->ec.Get()), entry->retainedBuf.GetMessageCounter(),
108+
entry->nextRetransTime.count());
109+
return Loop::Continue;
110+
});
111+
@@ -136,9 +136,9 @@ void ReliableMessageMgr::ExecuteActions()
112+
ExchangeHandle ec(entry->ec);
113+
114+
ChipLogError(ExchangeManager,
115+
- "Failed to Send CHIP MessageCounter:" ChipLogFormatMessageCounter " on exchange " ChipLogFormatExchange
116+
+ "Failed to Send CHIP MessageCounter:" ChipLogFormatMessageCounter " on exchange " ChipLogFormatExchangeExtended
117+
" sendCount: %u max retries: %d",
118+
- messageCounter, ChipLogValueExchange(&ec.Get()), sendCount, CHIP_CONFIG_RMP_DEFAULT_MAX_RETRANS);
119+
+ messageCounter, ChipLogValueExchangeExtended(&ec.Get()), sendCount, CHIP_CONFIG_RMP_DEFAULT_MAX_RETRANS);
120+
121+
// Don't check whether the session in the exchange is valid, because when the session is released, the retrans entry is
122+
// cleared inside ExchangeContext::OnSessionReleased, so the session must be valid if the entry exists.
123+
@@ -164,9 +164,9 @@ void ReliableMessageMgr::ExecuteActions()
124+
125+
entry->sendCount++;
126+
ChipLogProgress(ExchangeManager,
127+
- "Retransmitting MessageCounter:" ChipLogFormatMessageCounter " on exchange " ChipLogFormatExchange
128+
+ "Retransmitting MessageCounter:" ChipLogFormatMessageCounter " on exchange " ChipLogFormatExchangeExtended
129+
" Send Cnt %d",
130+
- messageCounter, ChipLogValueExchange(&entry->ec.Get()), entry->sendCount);
131+
+ messageCounter, ChipLogValueExchangeExtended(&entry->ec.Get()), entry->sendCount);
132+
133+
CalculateNextRetransTime(*entry);
134+
SendFromRetransTable(entry);
135+
@@ -284,8 +284,8 @@ bool ReliableMessageMgr::CheckAndRemRetransTable(ReliableMessageContext * rc, ui
136+
137+
ChipLogDetail(ExchangeManager,
138+
"Rxd Ack; Removing MessageCounter:" ChipLogFormatMessageCounter
139+
- " from Retrans Table on exchange " ChipLogFormatExchange,
140+
- ackMessageCounter, ChipLogValueExchange(rc->GetExchangeContext()));
141+
+ " from Retrans Table on exchange " ChipLogFormatExchangeExtended,
142+
+ ackMessageCounter, ChipLogValueExchangeExtended(rc->GetExchangeContext()));
143+
removed = true;
144+
return Loop::Break;
145+
}
146+
@@ -302,9 +302,9 @@ CHIP_ERROR ReliableMessageMgr::SendFromRetransTable(RetransTableEntry * entry)
147+
// Using same error message for all errors to reduce code size.
148+
ChipLogError(ExchangeManager,
149+
"Crit-err %" CHIP_ERROR_FORMAT " when sending CHIP MessageCounter:" ChipLogFormatMessageCounter
150+
- " on exchange " ChipLogFormatExchange ", send tries: %d",
151+
+ " on exchange " ChipLogFormatExchangeExtended ", send tries: %d",
152+
CHIP_ERROR_INCORRECT_STATE.Format(), entry->retainedBuf.GetMessageCounter(),
153+
- ChipLogValueExchange(&entry->ec.Get()), entry->sendCount);
154+
+ ChipLogValueExchangeExtended(&entry->ec.Get()), entry->sendCount);
155+
ClearRetransTable(*entry);
156+
return CHIP_ERROR_INCORRECT_STATE;
157+
}
158+
@@ -340,8 +340,8 @@ CHIP_ERROR ReliableMessageMgr::SendFromRetransTable(RetransTableEntry * entry)
159+
// Using same error message for all errors to reduce code size.
160+
ChipLogError(ExchangeManager,
161+
"Crit-err %" CHIP_ERROR_FORMAT " when sending CHIP MessageCounter:" ChipLogFormatMessageCounter
162+
- " on exchange " ChipLogFormatExchange ", send tries: %d",
163+
- err.Format(), entry->retainedBuf.GetMessageCounter(), ChipLogValueExchange(&entry->ec.Get()),
164+
+ " on exchange " ChipLogFormatExchangeExtended ", send tries: %d",
165+
+ err.Format(), entry->retainedBuf.GetMessageCounter(), ChipLogValueExchangeExtended(&entry->ec.Get()),
166+
entry->sendCount);
167+
168+
ClearRetransTable(*entry);
169+
--
170+
2.34.1
171+

0 commit comments

Comments
 (0)