diff --git a/.github/.wordlist.txt b/.github/.wordlist.txt index d0d8c0d9655462..9467074fdbcfd4 100644 --- a/.github/.wordlist.txt +++ b/.github/.wordlist.txt @@ -462,6 +462,7 @@ DV DVK dynload eabi +EAF EB ECC ECD @@ -552,6 +553,7 @@ feff ffaa ffeebaefa FFF +FFFFFFFFFFFF0102 fffe fffff Fi diff --git a/src/messaging/ExchangeMgr.cpp b/src/messaging/ExchangeMgr.cpp index b328be5df82dd5..b977c73b072d84 100644 --- a/src/messaging/ExchangeMgr.cpp +++ b/src/messaging/ExchangeMgr.cpp @@ -195,6 +195,16 @@ void ExchangeManager::OnMessageReceived(const PacketHeader & packetHeader, const auto * protocolName = Protocols::GetProtocolName(payloadHeader.GetProtocolID()); auto * msgTypeName = Protocols::GetMessageTypeName(payloadHeader.GetProtocolID(), payloadHeader.GetMessageType()); + auto destination = kUndefinedNodeId; + if (packetHeader.GetDestinationNodeId().HasValue()) + { + destination = packetHeader.GetDestinationNodeId().Value(); + } + else if (session->IsSecureSession()) + { + destination = session->AsSecureSession()->GetLocalNodeId(); + } + // // 32-bit value maximum = 10 chars + text preamble (6) + trailer (1) + null (1) + 2 buffer = 20 // @@ -220,18 +230,25 @@ void ExchangeManager::OnMessageReceived(const PacketHeader & packetHeader, const char typeStr[4 + 1 + 2 + 1]; snprintf(typeStr, sizeof(typeStr), "%04X:%02X", payloadHeader.GetProtocolID().GetProtocolId(), payloadHeader.GetMessageType()); + // More work around pigweed not allowing more than 14 format args in a log + // message when using tokenized logs. + // text(5) + fabricIndex (uint16_t, at most 5 chars) + text (1) + source (16) + text (2) + compressed fabric id (4) + text (5) + + // destination + null-terminator + char sourceDestinationStr[5 + 5 + 1 + 16 + 2 + 4 + 5 + 16 + 1]; + snprintf(sourceDestinationStr, sizeof(sourceDestinationStr), "from %u:" ChipLogFormatX64 " [%04X] to " ChipLogFormatX64, + session->GetFabricIndex(), ChipLogValueX64(session->GetPeer().GetNodeId()), static_cast(compressedFabricId), + ChipLogValueX64(destination)); + // // Legend that can be used to decode this log line can be found in README.md // - ChipLogProgress(ExchangeManager, - ">>> [E:" ChipLogFormatExchangeId " S:%u M:" ChipLogFormatMessageCounter - "%s] (%s) Msg RX from %u:" ChipLogFormatX64 " [%04X] --- Type %s (%s:%s) (B:%u)", - ChipLogValueExchangeIdFromReceivedHeader(payloadHeader), session->SessionIdForLogging(), - packetHeader.GetMessageCounter(), ackBuf, Transport::GetSessionTypeString(session), session->GetFabricIndex(), - ChipLogValueX64(session->GetPeer().GetNodeId()), static_cast(compressedFabricId), typeStr, - protocolName, msgTypeName, - static_cast(msgBuf->TotalLength() + packetHeader.EncodeSizeBytes() + packetHeader.MICTagLength() + - payloadHeader.EncodeSizeBytes())); + ChipLogProgress( + ExchangeManager, + ">>> [E:" ChipLogFormatExchangeId " S:%u M:" ChipLogFormatMessageCounter "%s] (%s) Msg RX %s --- Type %s (%s:%s) (B:%u)", + ChipLogValueExchangeIdFromReceivedHeader(payloadHeader), session->SessionIdForLogging(), packetHeader.GetMessageCounter(), + ackBuf, Transport::GetSessionTypeString(session), sourceDestinationStr, typeStr, protocolName, msgTypeName, + static_cast(msgBuf->TotalLength() + packetHeader.EncodeSizeBytes() + packetHeader.MICTagLength() + + payloadHeader.EncodeSizeBytes())); #endif MessageFlags msgFlags; diff --git a/src/messaging/README.md b/src/messaging/README.md index b439a45de6b840..b30d14637e61cc 100644 --- a/src/messaging/README.md +++ b/src/messaging/README.md @@ -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] [$peer_address] --- Type $protocol_id:$msg_type ($protocol_name:$msg_type_name) (B:$size) +<<< [E:$exchange_id S:$session_id M:$msg_id (Ack: $ack_msg_id)] ($msg_category) Msg TX from $source to $fabric_index:$destination [$compressed_fabric_id] [$peer_address] --- Type $protocol_id:$msg_type ($protocol_name:$msg_type_name) (B:$size) ``` | Field | Description | @@ -27,6 +27,7 @@ Unless specified, numerical values are represented in decimal notation. | ack_msg_id | If present, the ACK message counter. Otherwise, this entire field is omitted from display | | msg_category | U: Un-secure Unicast, S: Secure Unicast, G: Secure Groupcast | | fabric_index | Fabric index on the sending side | +| source | 64-bit Node Identifier that can represent both group, operational and temporary node identifiers depending on `$msg_category` (in hex) | | 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 | @@ -41,19 +42,19 @@ Unless specified, numerical values are represented in decimal notation. _Unencrypted Unicast:_ ``` -<<< [E:26341i S:0 M:264589322] (U) Msg TX to 0:0000000000000000 [0000] --- Type 0000:30 (SecureChannel:CASE_Sigma1) +<<< [E:26341i S:0 M:264589322] (U) Msg TX from 0FDE2AE2EAF5D74D to 0:0000000000000000 [0000] --- Type 0000:30 (SecureChannel:CASE_Sigma1) ``` _Secure Unicast:_ ``` -<<< [E:26347i S:5110 M:30642895 (Ack: 9203233)] (S) Msg TX to 1:0000000012344321 [1667] --- Type 0001:06 (IM:WriteRequest) +<<< [E:26347i S:5110 M:30642895 (Ack: 9203233)] (S) Msg TX from 000000000001B669 to 1:0000000012344321 [1667] --- Type 0001:06 (IM:WriteRequest) ``` _Secure Groupcast:_ ``` -<<< [E:26349i S:17850 M:2000] (G) Msg TX to 1:FFFFFFFFFFFF0102 [1667] --- Type 0001:06 (IM:WriteRequest) +<<< [E:26349i S:17850 M:2000] (G) Msg TX from 000000000001B669 to 1:FFFFFFFFFFFF0102 [1667] --- Type 0001:06 (IM:WriteRequest) ``` ### Message Reception @@ -66,7 +67,7 @@ will be expanded are denoted with `$` . Unless specified, numerical values are represented in decimal notation. ``` ->>> [E:$exchange_id M: $msg_id (Ack: $ack_msg_id)] ($msg_category) Msg RX from $fabric_index:$source [$compressed_fabric_id] --- Type $protocol_id:$msg_type ($protocol_name:$msg_type_name) (B:$size) +>>> [E:$exchange_id M: $msg_id (Ack: $ack_msg_id)] ($msg_category) Msg RX from $fabric_index:$source to $destination [$compressed_fabric_id] --- Type $protocol_id:$msg_type ($protocol_name:$msg_type_name) (B:$size) ``` This has a similar legend to that for transmission except `$source` denotes the @@ -77,17 +78,17 @@ source's node identifier and `$fabric_index` is the index on the recipient. _Unencrypted Unicast:_ ``` ->>> [E:26341i S:0 M:264589322] (U) Msg RX from 0:0FDE2AE2EAF5D74D [0000] --- Type 0000:30 (SecureChannel:CASE_Sigma1) +>>> [E:26341i S:0 M:264589322] (U) Msg RX from 0:0FDE2AE2EAF5D74D to 0000000000000000 [0000] --- Type 0000:30 (SecureChannel:CASE_Sigma1) ``` _Secure Unicast:_ ``` ->>> [E:26342i S:62311 M:30642885] (S) Msg RX from 1:000000000001B669 [1667] --- Type 0001:08 (IM:InvokeCommandRequest) +>>> [E:26342i S:62311 M:30642885] (S) Msg RX from 1:000000000001B669 to 0000000012344321 [1667] --- Type 0001:08 (IM:InvokeCommandRequest) ``` _Secure Groupcast:_ ``` ->>> [E:26349i S:1720 M:2000] (G) Msg RX from 1:000000000001B669 [0000] --- Type 0001:06 (IM:WriteRequest) +>>> [E:26349i S:1720 M:2000] (G) Msg RX from 1:000000000001B669 to FFFFFFFFFFFF0102 [0000] --- Type 0001:06 (IM:WriteRequest) ``` diff --git a/src/transport/SessionManager.cpp b/src/transport/SessionManager.cpp index d68a5f3e6e6480..5a895e8054c41b 100644 --- a/src/transport/SessionManager.cpp +++ b/src/transport/SessionManager.cpp @@ -220,6 +220,7 @@ CHIP_ERROR SessionManager::PrepareMessage(const SessionHandle & sessionHandle, P FabricIndex fabricIndex; #endif // CHIP_PROGRESS_LOGGING + NodeId sourceNodeId = kUndefinedNodeId; PeerAddress destination_address; switch (sessionHandle->GetSessionType()) @@ -236,7 +237,7 @@ CHIP_ERROR SessionManager::PrepareMessage(const SessionHandle & sessionHandle, P packetHeader.SetMessageCounter(mGroupClientCounter.GetCounter(isControlMsg)); mGroupClientCounter.IncrementCounter(isControlMsg); packetHeader.SetSessionType(Header::SessionType::kGroupSession); - NodeId sourceNodeId = fabric->GetNodeId(); + sourceNodeId = fabric->GetNodeId(); packetHeader.SetSourceNodeId(sourceNodeId); if (!packetHeader.IsValidGroupMsg()) @@ -292,7 +293,7 @@ CHIP_ERROR SessionManager::PrepareMessage(const SessionHandle & sessionHandle, P CHIP_TRACE_MESSAGE_SENT(payloadHeader, packetHeader, destination_address, message->Start(), message->TotalLength()); CryptoContext::NonceStorage nonce; - NodeId sourceNodeId = session->GetLocalScopedNodeId().GetNodeId(); + sourceNodeId = session->GetLocalScopedNodeId().GetNodeId(); CryptoContext::BuildNonce(nonce, packetHeader.GetSecurityFlags(), messageCounter, sourceNodeId); ReturnErrorOnFailure(SecureMessageCodec::Encrypt(session->GetCryptoContext(), nonce, payloadHeader, packetHeader, message)); @@ -336,6 +337,10 @@ CHIP_ERROR SessionManager::PrepareMessage(const SessionHandle & sessionHandle, P { destination = session->GetEphemeralInitiatorNodeID(); } + else if (session->GetSessionRole() == Transport::UnauthenticatedSession::SessionRole::kInitiator) + { + sourceNodeId = session->GetEphemeralInitiatorNodeID(); + } #endif // CHIP_PROGRESS_LOGGING } break; @@ -386,16 +391,22 @@ CHIP_ERROR SessionManager::PrepareMessage(const SessionHandle & sessionHandle, P char exchangeStr[5 + 1 + 1]; snprintf(exchangeStr, sizeof(exchangeStr), ChipLogFormatExchangeId, ChipLogValueExchangeIdFromSentHeader(payloadHeader)); + // More work around pigweed not allowing more than 14 format args in a log + // message when using tokenized logs. + // text(5) + source(16) + text(4) + fabricIndex(uint16_t, at most 5 chars) + text(1) + destination(16) + text(2) + compressed + // fabric id(4) + text(1) + null-terminator + char sourceDestinationStr[5 + 16 + 4 + 5 + 1 + 16 + 2 + 4 + 1 + 1]; + snprintf(sourceDestinationStr, sizeof(sourceDestinationStr), "from " ChipLogFormatX64 " to %u:" ChipLogFormatX64 " [%04X]", + ChipLogValueX64(sourceNodeId), fabricIndex, ChipLogValueX64(destination), static_cast(compressedFabricId)); + // // Legend that can be used to decode this log line can be found in messaging/README.md // ChipLogProgress(ExchangeManager, - "<<< [E:%s S:%u M:" ChipLogFormatMessageCounter "%s] (%s) Msg TX to %u:" ChipLogFormatX64 - " [%04X] [%s] --- Type %s (%s:%s) (B:%u)", + "<<< [E:%s S:%u M:" ChipLogFormatMessageCounter "%s] (%s) Msg TX %s [%s] --- Type %s (%s:%s) (B:%u)", exchangeStr, sessionHandle->SessionIdForLogging(), packetHeader.GetMessageCounter(), ackBuf, - Transport::GetSessionTypeString(sessionHandle), fabricIndex, ChipLogValueX64(destination), - static_cast(compressedFabricId), addressStr, typeStr, protocolName, msgTypeName, - static_cast(message->TotalLength())); + Transport::GetSessionTypeString(sessionHandle), sourceDestinationStr, addressStr, typeStr, protocolName, + msgTypeName, static_cast(message->TotalLength())); #endif preparedMessage = EncryptedPacketBufferHandle::MarkEncrypted(std::move(message));