Skip to content

Commit

Permalink
Include the peer address in "Msg TX" logs.
Browse files Browse the repository at this point in the history 
We had our logging split up into a "Msg TX" log that listed all sorts of info
but not the peer address and some "Sending msg" logs that listed the peer
address for group and unauthenticated messages, but not secure ones.  In the
secure case the "Sending msg" log showed no information that was not also shown
by the "Msg TX" log.

The "Sending msg" log did get shown for MRP retransmits, but those are also
logged with "Retransmitting MessageCounter:" logs that allow them to be
correlated with the relevant initial "Msg TX" log.

The fix here is:

1) Add peer address info in the "Msg TX" logs.
2) Remove the now-redunant "Sending msg" logs.
  • Loading branch information
@bzbarsky-apple
bzbarsky-apple committed Sep 20, 2023
1 parent a190015 commit 8a94b07
Show file tree
Hide file tree
Showing 2 changed files with 29 additions and 19 deletions.
3 changes: 2 additions & 1 deletion src/messaging/README.md
View file
Original file line number Diff line number Diff line change
Expand Up @@ -16,7 +16,7 @@ will be expanded are denoted with `$` .
Unless specified, numerical values are represented in decimal notation.

```
<<< [E:$exchange_id S:$session_id M:$msg_id (Ack: $ack_msg_id)] ($msg_category) Msg TX to $fabric_index:$destination [$compressed_fabric_id] --- Type $protocol_id:$msg_type ($protocol_name:$msg_type_name)
<<< [E:$exchange_id S:$session_id M:$msg_id (Ack: $ack_msg_id)] ($msg_category) Msg TX to $fabric_index:$destination [$compressed_fabric_id] [$peer_address] --- Type $protocol_id:$msg_type ($protocol_name:$msg_type_name)
```

| Field | Description |
Expand All @@ -29,6 +29,7 @@ Unless specified, numerical values are represented in decimal notation.
| fabric_index | Fabric index on the sending side |
| destination | 64-bit Node Identifier that can represent both group, operational and temporary node identifiers depending on `$msg_category` (in hex) |
| compressed_fabric_id | If present and valid, lower 16-bits of the compressed fabric ID (in hex). Otherwise, it will be set to 0000. |
| peer_address | The peer address (IP and port) for the session |
| protocol_id | 16-bit Protocol ID within the common vendor namespace (in hex) |
| msg_type | 8-bit message type ID (in hex) |
| protocol_name | If available, a logical name for the protocol |
Expand Down
45 changes: 27 additions & 18 deletions src/transport/SessionManager.cpp
View file
Original file line number Diff line number Diff line change
Expand Up @@ -304,15 +304,40 @@ CHIP_ERROR SessionManager::PrepareMessage(const SessionHandle & sessionHandle, P
snprintf(ackBuf, sizeof(ackBuf), " (Ack:" ChipLogFormatMessageCounter ")", payloadHeader.GetAckMessageCounter().Value());
}

char addressStr[Transport::PeerAddress::kMaxToStringSize] = { 0 };
switch (sessionHandle->GetSessionType())
{
case Transport::Session::SessionType::kGroupOutgoing: {
// We already checked above that we have a fabric entry for our fabric
// index.
auto * groupSession = sessionHandle->AsOutgoingGroupSession();
auto * fabricInfo = mFabricTable->FindFabricWithIndex(fabricIndex);
auto multicastAddress = Transport::PeerAddress::Multicast(fabricInfo->GetFabricId(), groupSession->GetGroupId());
multicastAddress.ToString(addressStr);
break;
}
case Transport::Session::SessionType::kSecure: {
sessionHandle->AsSecureSession()->GetPeerAddress().ToString(addressStr);
break;
}
case Transport::Session::SessionType::kUnauthenticated: {
sessionHandle->AsUnauthenticatedSession()->GetPeerAddress().ToString(addressStr);
break;
}
default:
// Note: We checked above that we are one of these three session types.
break;
}

//
// Legend that can be used to decode this log line can be found in messaging/README.md
//
ChipLogProgress(ExchangeManager,
"<<< [E:" ChipLogFormatExchangeId " S:%u M:" ChipLogFormatMessageCounter
"%s] (%s) Msg TX to %u:" ChipLogFormatX64 " [%04X] --- Type %04X:%02X (%s:%s)",
"%s] (%s) Msg TX to %u:" ChipLogFormatX64 " [%04X] [%s] --- Type %04X:%02X (%s:%s)",
ChipLogValueExchangeIdFromSentHeader(payloadHeader), sessionHandle->SessionIdForLogging(),
packetHeader.GetMessageCounter(), ackBuf, Transport::GetSessionTypeString(sessionHandle), fabricIndex,
ChipLogValueX64(destination), static_cast<uint16_t>(compressedFabricId),
ChipLogValueX64(destination), static_cast<uint16_t>(compressedFabricId), addressStr,
payloadHeader.GetProtocolID().GetProtocolId(), payloadHeader.GetMessageType(), protocolName, msgTypeName);
#endif

Expand Down Expand Up @@ -341,11 +366,6 @@ CHIP_ERROR SessionManager::SendPreparedMessage(const SessionHandle & sessionHand

multicastAddress = Transport::PeerAddress::Multicast(fabric->GetFabricId(), groupSession->GetGroupId());
destination = &multicastAddress;
char addressStr[Transport::PeerAddress::kMaxToStringSize];
multicastAddress.ToString(addressStr, Transport::PeerAddress::kMaxToStringSize);

ChipLogProgress(Inet, "(G) Sending msg " ChipLogFormatMessageCounter " to Multicast IPV6 address '%s'",
preparedMessage.GetMessageCounter(), addressStr);
}
break;
case Transport::Session::SessionType::kSecure: {
Expand All @@ -356,23 +376,12 @@ CHIP_ERROR SessionManager::SendPreparedMessage(const SessionHandle & sessionHand
secure->MarkActive();

destination = &secure->GetPeerAddress();

ChipLogProgress(Inet, "(S) Sending msg " ChipLogFormatMessageCounter " on secure session with LSID: %u",
preparedMessage.GetMessageCounter(), secure->GetLocalSessionId());
}
break;
case Transport::Session::SessionType::kUnauthenticated: {
auto unauthenticated = sessionHandle->AsUnauthenticatedSession();
unauthenticated->MarkActive();
destination = &unauthenticated->GetPeerAddress();

#if CHIP_PROGRESS_LOGGING
char addressStr[Transport::PeerAddress::kMaxToStringSize];
destination->ToString(addressStr);

ChipLogProgress(Inet, "(U) Sending msg " ChipLogFormatMessageCounter " to IP address '%s'",
preparedMessage.GetMessageCounter(), addressStr);
#endif
}
break;
default:
Expand Down

0 comments on commit 8a94b07

Please sign in to comment.