Line data Source code
1 : /*
2 : * Copyright (c) 2020-2021 Project CHIP Authors
3 : * All rights reserved.
4 : *
5 : * Licensed under the Apache License, Version 2.0 (the "License");
6 : * you may not use this file except in compliance with the License.
7 : * You may obtain a copy of the License at
8 : *
9 : * http://www.apache.org/licenses/LICENSE-2.0
10 : *
11 : * Unless required by applicable law or agreed to in writing, software
12 : * distributed under the License is distributed on an "AS IS" BASIS,
13 : * WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied.
14 : * See the License for the specific language governing permissions and
15 : * limitations under the License.
16 : */
17 :
18 : /**
19 : * @file
20 : * This file implements the CHIP reliable message protocol.
21 : *
22 : */
23 :
24 : #include <errno.h>
25 : #include <inttypes.h>
26 :
27 : #include <lib/support/BitFlags.h>
28 : #include <lib/support/CHIPFaultInjection.h>
29 : #include <lib/support/CodeUtils.h>
30 : #include <lib/support/logging/CHIPLogging.h>
31 : #include <messaging/ErrorCategory.h>
32 : #include <messaging/ExchangeMessageDispatch.h>
33 : #include <messaging/ExchangeMgr.h>
34 : #include <messaging/Flags.h>
35 : #include <messaging/ReliableMessageContext.h>
36 : #include <messaging/ReliableMessageMgr.h>
37 : #include <platform/ConnectivityManager.h>
38 :
39 : #if CHIP_CONFIG_ENABLE_ICD_SERVER
40 : #include <app/icd/server/ICDConfigurationData.h> // nogncheck
41 : #include <app/icd/server/ICDNotifier.h> // nogncheck
42 : #endif
43 :
44 : using namespace chip::System::Clock::Literals;
45 :
46 : namespace chip {
47 : namespace Messaging {
48 :
49 7920 : ReliableMessageMgr::RetransTableEntry::RetransTableEntry(ReliableMessageContext * rc) :
50 7920 : ec(*rc->GetExchangeContext()), nextRetransTime(0), sendCount(0)
51 : {
52 7920 : ec->SetWaitingForAck(true);
53 7920 : }
54 :
55 7920 : ReliableMessageMgr::RetransTableEntry::~RetransTableEntry()
56 : {
57 7920 : ec->SetWaitingForAck(false);
58 7920 : }
59 :
60 76 : ReliableMessageMgr::ReliableMessageMgr(ObjectPool<ExchangeContext, CHIP_CONFIG_MAX_EXCHANGE_CONTEXTS> & contextPool) :
61 76 : mContextPool(contextPool), mSystemLayer(nullptr)
62 76 : {}
63 :
64 76 : ReliableMessageMgr::~ReliableMessageMgr() {}
65 :
66 309 : void ReliableMessageMgr::Init(chip::System::Layer * systemLayer)
67 : {
68 309 : mSystemLayer = systemLayer;
69 309 : }
70 :
71 309 : void ReliableMessageMgr::Shutdown()
72 : {
73 309 : StopTimer();
74 :
75 : // Clear the retransmit table
76 309 : mRetransTable.ForEachActiveObject([&](auto * entry) {
77 9 : mRetransTable.ReleaseObject(entry);
78 9 : return Loop::Continue;
79 : });
80 :
81 309 : mSystemLayer = nullptr;
82 309 : }
83 :
84 23827 : void ReliableMessageMgr::TicklessDebugDumpRetransTable(const char * log)
85 : {
86 : #if defined(RMP_TICKLESS_DEBUG)
87 : ChipLogDetail(ExchangeManager, "%s", log);
88 :
89 : mRetransTable.ForEachActiveObject([&](auto * entry) {
90 : ChipLogDetail(ExchangeManager,
91 : "EC:" ChipLogFormatExchange " MessageCounter:" ChipLogFormatMessageCounter
92 : " NextRetransTimeCtr: 0x" ChipLogFormatX64,
93 : ChipLogValueExchange(&entry->ec.Get()), entry->retainedBuf.GetMessageCounter(),
94 : ChipLogValueX64(entry->nextRetransTime.count()));
95 : return Loop::Continue;
96 : });
97 : #endif
98 23827 : }
99 :
100 74 : void ReliableMessageMgr::ExecuteActions()
101 : {
102 74 : System::Clock::Timestamp now = System::SystemClock().GetMonotonicTimestamp();
103 :
104 : #if defined(RMP_TICKLESS_DEBUG)
105 : ChipLogDetail(ExchangeManager, "ReliableMessageMgr::ExecuteActions at 0x" ChipLogFormatX64 "ms", ChipLogValueX64(now.count()));
106 : #endif
107 :
108 74 : ExecuteForAllContext([&](ReliableMessageContext * rc) {
109 119 : if (rc->IsAckPending())
110 : {
111 0 : if (rc->mNextAckTime <= now)
112 : {
113 : #if defined(RMP_TICKLESS_DEBUG)
114 : ChipLogDetail(ExchangeManager, "ReliableMessageMgr::ExecuteActions sending ACK %p", rc);
115 : #endif
116 0 : rc->SendStandaloneAckMessage();
117 : }
118 : }
119 119 : });
120 :
121 : // Retransmit / cancel anything in the retrans table whose retrans timeout has expired
122 74 : mRetransTable.ForEachActiveObject([&](auto * entry) {
123 96 : if (entry->nextRetransTime > now)
124 19 : return Loop::Continue;
125 :
126 77 : VerifyOrDie(!entry->retainedBuf.IsNull());
127 :
128 77 : uint8_t sendCount = entry->sendCount;
129 : #if CHIP_ERROR_LOGGING || CHIP_DETAIL_LOGGING
130 77 : uint32_t messageCounter = entry->retainedBuf.GetMessageCounter();
131 : #endif // CHIP_ERROR_LOGGING || CHIP_DETAIL_LOGGING
132 :
133 77 : if (sendCount == CHIP_CONFIG_RMP_DEFAULT_MAX_RETRANS)
134 : {
135 : // Make sure our exchange stays alive until we are done working with it.
136 11 : ExchangeHandle ec(entry->ec);
137 :
138 11 : ChipLogError(ExchangeManager,
139 : "Failed to Send CHIP MessageCounter:" ChipLogFormatMessageCounter " on exchange " ChipLogFormatExchange
140 : " sendCount: %u max retries: %d",
141 : messageCounter, ChipLogValueExchange(&ec.Get()), sendCount, CHIP_CONFIG_RMP_DEFAULT_MAX_RETRANS);
142 :
143 : // Don't check whether the session in the exchange is valid, because when the session is released, the retrans entry is
144 : // cleared inside ExchangeContext::OnSessionReleased, so the session must be valid if the entry exists.
145 11 : SessionHandle session = ec->GetSessionHandle();
146 :
147 : // If the exchange is expecting a response, it will handle sending
148 : // this notification once it detects that it has not gotten a
149 : // response. Otherwise, we need to do it.
150 11 : if (!ec->IsResponseExpected())
151 : {
152 3 : if (session->IsSecureSession() && session->AsSecureSession()->IsCASESession())
153 : {
154 2 : session->AsSecureSession()->MarkAsDefunct();
155 : }
156 3 : session->DispatchSessionEvent(&SessionDelegate::OnSessionHang);
157 : }
158 :
159 : // Do not StartTimer, we will schedule the timer at the end of the timer handler.
160 11 : mRetransTable.ReleaseObject(entry);
161 :
162 11 : return Loop::Continue;
163 11 : }
164 :
165 66 : entry->sendCount++;
166 66 : ChipLogProgress(ExchangeManager,
167 : "Retransmitting MessageCounter:" ChipLogFormatMessageCounter " on exchange " ChipLogFormatExchange
168 : " Send Cnt %d",
169 : messageCounter, ChipLogValueExchange(&entry->ec.Get()), entry->sendCount);
170 :
171 66 : CalculateNextRetransTime(*entry);
172 66 : SendFromRetransTable(entry);
173 :
174 66 : return Loop::Continue;
175 : });
176 :
177 74 : TicklessDebugDumpRetransTable("ReliableMessageMgr::ExecuteActions Dumping mRetransTable entries after processing");
178 74 : }
179 :
180 74 : void ReliableMessageMgr::Timeout(System::Layer * aSystemLayer, void * aAppState)
181 : {
182 74 : ReliableMessageMgr * manager = reinterpret_cast<ReliableMessageMgr *>(aAppState);
183 :
184 74 : VerifyOrDie((aSystemLayer != nullptr) && (manager != nullptr));
185 :
186 : #if defined(RMP_TICKLESS_DEBUG)
187 : ChipLogDetail(ExchangeManager, "ReliableMessageMgr::Timeout");
188 : #endif
189 :
190 : // Execute any actions that are due this tick
191 74 : manager->ExecuteActions();
192 :
193 : // Calculate next physical wakeup
194 74 : manager->StartTimer();
195 74 : }
196 :
197 7920 : CHIP_ERROR ReliableMessageMgr::AddToRetransTable(ReliableMessageContext * rc, RetransTableEntry ** rEntry)
198 : {
199 7920 : VerifyOrDie(!rc->IsWaitingForAck());
200 :
201 7920 : *rEntry = mRetransTable.CreateObject(rc);
202 7920 : if (*rEntry == nullptr)
203 : {
204 0 : ChipLogError(ExchangeManager, "mRetransTable Already Full");
205 0 : return CHIP_ERROR_RETRANS_TABLE_FULL;
206 : }
207 :
208 7920 : return CHIP_NO_ERROR;
209 : }
210 :
211 41203 : System::Clock::Timestamp ReliableMessageMgr::GetBackoff(System::Clock::Timestamp baseInterval, uint8_t sendCount,
212 : bool computeMaxPossible)
213 : {
214 : // See section "4.11.8. Parameters and Constants" for the parameters below:
215 : // MRP_BACKOFF_JITTER = 0.25
216 41203 : constexpr uint32_t MRP_BACKOFF_JITTER_BASE = 1024;
217 : // MRP_BACKOFF_MARGIN = 1.1
218 41203 : constexpr uint32_t MRP_BACKOFF_MARGIN_NUMERATOR = 1127;
219 41203 : constexpr uint32_t MRP_BACKOFF_MARGIN_DENOMINATOR = 1024;
220 : // MRP_BACKOFF_BASE = 1.6
221 41203 : constexpr uint32_t MRP_BACKOFF_BASE_NUMERATOR = 16;
222 41203 : constexpr uint32_t MRP_BACKOFF_BASE_DENOMINATOR = 10;
223 41203 : constexpr int MRP_BACKOFF_THRESHOLD = 1;
224 :
225 : // Implement `i = MRP_BACKOFF_MARGIN * i` from section "4.11.2.1. Retransmissions", where:
226 : // i == baseInterval
227 41203 : baseInterval = baseInterval * MRP_BACKOFF_MARGIN_NUMERATOR / MRP_BACKOFF_MARGIN_DENOMINATOR;
228 :
229 : // Implement:
230 : // mrpBackoffTime = i * MRP_BACKOFF_BASE^(max(0,n-MRP_BACKOFF_THRESHOLD)) * (1.0 + random(0,1) * MRP_BACKOFF_JITTER)
231 : // from section "4.11.2.1. Retransmissions", where:
232 : // i == baseInterval
233 : // n == sendCount
234 :
235 : // 1. Calculate exponent `max(0,n−MRP_BACKOFF_THRESHOLD)`
236 41203 : int exponent = sendCount - MRP_BACKOFF_THRESHOLD;
237 41203 : if (exponent < 0)
238 14557 : exponent = 0; // Enforce floor
239 41203 : if (exponent > 4)
240 6 : exponent = 4; // Enforce reasonable maximum after 5 tries
241 :
242 : // 2. Calculate `mrpBackoffTime = i * MRP_BACKOFF_BASE^(max(0,n-MRP_BACKOFF_THRESHOLD))`
243 41203 : uint32_t backoffNum = 1;
244 41203 : uint32_t backoffDenom = 1;
245 :
246 81183 : for (int i = 0; i < exponent; i++)
247 : {
248 39980 : backoffNum *= MRP_BACKOFF_BASE_NUMERATOR;
249 39980 : backoffDenom *= MRP_BACKOFF_BASE_DENOMINATOR;
250 : }
251 :
252 41203 : System::Clock::Timestamp mrpBackoffTime = baseInterval * backoffNum / backoffDenom;
253 :
254 : // 3. Calculate `mrpBackoffTime *= (1.0 + random(0,1) * MRP_BACKOFF_JITTER)`
255 41203 : uint32_t jitter = MRP_BACKOFF_JITTER_BASE + (computeMaxPossible ? UINT8_MAX : Crypto::GetRandU8());
256 41203 : mrpBackoffTime = mrpBackoffTime * jitter / MRP_BACKOFF_JITTER_BASE;
257 :
258 : #if CHIP_CONFIG_ENABLE_ICD_SERVER
259 : // Implement:
260 : // "An ICD sender SHOULD increase t to also account for its own sleepy interval
261 : // required to receive the acknowledgment"
262 : mrpBackoffTime += ICDConfigurationData::GetInstance().GetFastPollingInterval();
263 : #endif
264 :
265 41203 : mrpBackoffTime += CHIP_CONFIG_MRP_RETRY_INTERVAL_SENDER_BOOST;
266 :
267 41203 : return mrpBackoffTime;
268 : }
269 :
270 7915 : void ReliableMessageMgr::StartRetransmision(RetransTableEntry * entry)
271 : {
272 7915 : CalculateNextRetransTime(*entry);
273 7915 : StartTimer();
274 7915 : }
275 :
276 7786 : bool ReliableMessageMgr::CheckAndRemRetransTable(ReliableMessageContext * rc, uint32_t ackMessageCounter)
277 : {
278 7786 : bool removed = false;
279 7786 : mRetransTable.ForEachActiveObject([&](auto * entry) {
280 19930 : if (entry->ec->GetReliableMessageContext() == rc && entry->retainedBuf.GetMessageCounter() == ackMessageCounter)
281 : {
282 : // Clear the entry from the retransmision table.
283 7775 : ClearRetransTable(*entry);
284 :
285 7775 : ChipLogDetail(ExchangeManager,
286 : "Rxd Ack; Removing MessageCounter:" ChipLogFormatMessageCounter
287 : " from Retrans Table on exchange " ChipLogFormatExchange,
288 : ackMessageCounter, ChipLogValueExchange(rc->GetExchangeContext()));
289 7775 : removed = true;
290 7775 : return Loop::Break;
291 : }
292 12155 : return Loop::Continue;
293 : });
294 :
295 7786 : return removed;
296 : }
297 :
298 66 : CHIP_ERROR ReliableMessageMgr::SendFromRetransTable(RetransTableEntry * entry)
299 : {
300 66 : if (!entry->ec->HasSessionHandle())
301 : {
302 : // Using same error message for all errors to reduce code size.
303 0 : ChipLogError(ExchangeManager,
304 : "Crit-err %" CHIP_ERROR_FORMAT " when sending CHIP MessageCounter:" ChipLogFormatMessageCounter
305 : " on exchange " ChipLogFormatExchange ", send tries: %d",
306 : CHIP_ERROR_INCORRECT_STATE.Format(), entry->retainedBuf.GetMessageCounter(),
307 : ChipLogValueExchange(&entry->ec.Get()), entry->sendCount);
308 0 : ClearRetransTable(*entry);
309 0 : return CHIP_ERROR_INCORRECT_STATE;
310 : }
311 :
312 66 : auto * sessionManager = entry->ec->GetExchangeMgr()->GetSessionManager();
313 66 : CHIP_ERROR err = sessionManager->SendPreparedMessage(entry->ec->GetSessionHandle(), entry->retainedBuf);
314 66 : err = MapSendError(err, entry->ec->GetExchangeId(), entry->ec->IsInitiator());
315 :
316 66 : if (err == CHIP_NO_ERROR)
317 : {
318 : #if CHIP_CONFIG_ENABLE_ICD_SERVER
319 : app::ICDNotifier::GetInstance().NotifyNetworkActivityNotification();
320 : #endif // CHIP_CONFIG_ENABLE_ICD_SERVER
321 : #if CHIP_CONFIG_RESOLVE_PEER_ON_FIRST_TRANSMIT_FAILURE
322 : const ExchangeManager * exchangeMgr = entry->ec->GetExchangeMgr();
323 : // TODO: investigate why in ReliableMessageMgr::CheckResendApplicationMessageWithPeerExchange unit test released exchange
324 : // context with mExchangeMgr==nullptr is used.
325 : if (exchangeMgr)
326 : {
327 : // After the first failure notify session manager to refresh device data
328 : if (entry->sendCount == 1 && mSessionUpdateDelegate != nullptr && entry->ec->GetSessionHandle()->IsSecureSession() &&
329 : entry->ec->GetSessionHandle()->AsSecureSession()->IsCASESession())
330 : {
331 : ChipLogDetail(ExchangeManager, "Notify session manager to update peer address");
332 : mSessionUpdateDelegate->UpdatePeerAddress(entry->ec->GetSessionHandle()->GetPeer());
333 : }
334 : }
335 : #endif // CHIP_CONFIG_RESOLVE_PEER_ON_FIRST_TRANSMIT_FAILURE
336 : }
337 : else
338 : {
339 : // Remove from table
340 : // Using same error message for all errors to reduce code size.
341 0 : ChipLogError(ExchangeManager,
342 : "Crit-err %" CHIP_ERROR_FORMAT " when sending CHIP MessageCounter:" ChipLogFormatMessageCounter
343 : " on exchange " ChipLogFormatExchange ", send tries: %d",
344 : err.Format(), entry->retainedBuf.GetMessageCounter(), ChipLogValueExchange(&entry->ec.Get()),
345 : entry->sendCount);
346 :
347 0 : ClearRetransTable(*entry);
348 : }
349 66 : return err;
350 : }
351 :
352 233 : void ReliableMessageMgr::ClearRetransTable(ReliableMessageContext * rc)
353 : {
354 233 : mRetransTable.ForEachActiveObject([&](auto * entry) {
355 220 : if (entry->ec->GetReliableMessageContext() == rc)
356 : {
357 120 : ClearRetransTable(*entry);
358 120 : return Loop::Break;
359 : }
360 100 : return Loop::Continue;
361 : });
362 233 : }
363 :
364 7900 : void ReliableMessageMgr::ClearRetransTable(RetransTableEntry & entry)
365 : {
366 7900 : mRetransTable.ReleaseObject(&entry);
367 : // Expire any virtual ticks that have expired so all wakeup sources reflect the current time
368 7900 : StartTimer();
369 7900 : }
370 :
371 23753 : void ReliableMessageMgr::StartTimer()
372 : {
373 : // When do we need to next wake up to send an ACK?
374 23753 : System::Clock::Timestamp nextWakeTime = System::Clock::Timestamp::max();
375 :
376 23753 : ExecuteForAllContext([&](ReliableMessageContext * rc) {
377 152823 : if (rc->IsAckPending() && rc->mNextAckTime < nextWakeTime)
378 : {
379 9623 : nextWakeTime = rc->mNextAckTime;
380 : }
381 152823 : });
382 :
383 : // When do we need to next wake up for ReliableMessageProtocol retransmit?
384 23753 : mRetransTable.ForEachActiveObject([&](auto * entry) {
385 91158 : if (entry->nextRetransTime < nextWakeTime)
386 : {
387 16679 : nextWakeTime = entry->nextRetransTime;
388 : }
389 91158 : return Loop::Continue;
390 : });
391 :
392 23753 : StopTimer();
393 :
394 23753 : if (nextWakeTime != System::Clock::Timestamp::max())
395 : {
396 22424 : const System::Clock::Timestamp now = System::SystemClock().GetMonotonicTimestamp();
397 22424 : const auto nextWakeDelay = (nextWakeTime > now) ? nextWakeTime - now : 0_ms;
398 :
399 : #if defined(RMP_TICKLESS_DEBUG)
400 : ChipLogDetail(ExchangeManager,
401 : "ReliableMessageMgr::StartTimer at 0x" ChipLogFormatX64 "ms wake at 0x" ChipLogFormatX64
402 : "ms (in 0x" ChipLogFormatX64 "ms)",
403 : ChipLogValueX64(now.count()), ChipLogValueX64(nextWakeTime.count()), ChipLogValueX64(nextWakeDelay.count()));
404 : #endif
405 22424 : VerifyOrDie(mSystemLayer->StartTimer(nextWakeDelay, Timeout, this) == CHIP_NO_ERROR);
406 : }
407 : else
408 : {
409 : #if defined(RMP_TICKLESS_DEBUG)
410 : ChipLogDetail(ExchangeManager, "ReliableMessageMgr skipped timer");
411 : #endif
412 : }
413 :
414 23753 : TicklessDebugDumpRetransTable("ReliableMessageMgr::StartTimer Dumping mRetransTable entries after setting wakeup times");
415 23753 : }
416 :
417 24068 : void ReliableMessageMgr::StopTimer()
418 : {
419 24068 : mSystemLayer->CancelTimer(Timeout, this);
420 24068 : }
421 :
422 2 : void ReliableMessageMgr::RegisterSessionUpdateDelegate(SessionUpdateDelegate * sessionUpdateDelegate)
423 : {
424 2 : mSessionUpdateDelegate = sessionUpdateDelegate;
425 2 : }
426 :
427 7985 : CHIP_ERROR ReliableMessageMgr::MapSendError(CHIP_ERROR error, uint16_t exchangeId, bool isInitiator)
428 : {
429 7985 : if (
430 : #if CHIP_SYSTEM_CONFIG_USE_LWIP
431 : error == System::MapErrorLwIP(ERR_MEM)
432 : #else
433 7985 : error == CHIP_ERROR_POSIX(ENOBUFS)
434 : #endif // CHIP_SYSTEM_CONFIG_USE_LWIP
435 : )
436 : {
437 : // sendmsg on BSD-based systems never blocks, no matter how the
438 : // socket is configured, and will return ENOBUFS in situation in
439 : // which Linux, for example, blocks.
440 : //
441 : // This is typically a transient situation, so we pretend like this
442 : // packet drop happened somewhere on the network instead of inside
443 : // sendmsg and will just resend it in the normal MRP way later.
444 : //
445 : // Similarly, on LwIP an ERR_MEM on send indicates a likely
446 : // temporary lack of TX buffers.
447 0 : ChipLogError(ExchangeManager, "Ignoring transient send error: %" CHIP_ERROR_FORMAT " on exchange " ChipLogFormatExchangeId,
448 : error.Format(), ChipLogValueExchangeId(exchangeId, isInitiator));
449 0 : error = CHIP_NO_ERROR;
450 : }
451 :
452 7985 : return error;
453 : }
454 :
455 7981 : void ReliableMessageMgr::CalculateNextRetransTime(RetransTableEntry & entry)
456 : {
457 7981 : System::Clock::Timestamp baseTimeout = System::Clock::Milliseconds64(0);
458 :
459 : // Check if we have received at least one application-level message
460 7981 : if (entry.ec->HasReceivedAtLeastOneMessage())
461 : {
462 : // If we have received at least one message, assume peer is active and use ActiveRetransTimeout
463 6342 : baseTimeout = entry.ec->GetSessionHandle()->GetRemoteMRPConfig().mActiveRetransTimeout;
464 : }
465 : else
466 : {
467 : // If we haven't received at least one message
468 : // Choose active/idle timeout from PeerActiveMode of session per 4.11.2.1. Retransmissions.
469 1639 : baseTimeout = entry.ec->GetSessionHandle()->GetMRPBaseTimeout();
470 : }
471 :
472 7981 : System::Clock::Timestamp backoff = ReliableMessageMgr::GetBackoff(baseTimeout, entry.sendCount);
473 7981 : entry.nextRetransTime = System::SystemClock().GetMonotonicTimestamp() + backoff;
474 7981 : }
475 :
476 : #if CHIP_CONFIG_TEST
477 25849 : int ReliableMessageMgr::TestGetCountRetransTable()
478 : {
479 25849 : int count = 0;
480 25849 : mRetransTable.ForEachActiveObject([&](auto * entry) {
481 26445 : count++;
482 26445 : return Loop::Continue;
483 : });
484 25849 : return count;
485 : }
486 : #endif // CHIP_CONFIG_TEST
487 :
488 : } // namespace Messaging
489 : } // namespace chip
|