From dc66009671f5e45408a7cfcd3c90501a9ada216a Mon Sep 17 00:00:00 2001 From: Carol Yang Date: Thu, 28 Oct 2021 15:29:06 -0700 Subject: [PATCH 1/3] Add logging for OTA QueryImage, AnnounceOTAProvider, and BDX Output Event Type - These logs are to be parsed from testing side for test validation --- .../ota-provider-common/BdxOtaSender.cpp | 2 +- .../ota-requestor-common/BDXDownloader.cpp | 2 +- .../ExampleOTARequestor.cpp | 12 +++++-- .../clusters/ota-provider/ota-provider.cpp | 10 +++++- src/protocols/bdx/BdxTransferSession.cpp | 31 +++++++++++++++++++ src/protocols/bdx/BdxTransferSession.h | 2 ++ 6 files changed, 54 insertions(+), 5 deletions(-) diff --git a/examples/ota-provider-app/ota-provider-common/BdxOtaSender.cpp b/examples/ota-provider-app/ota-provider-common/BdxOtaSender.cpp index 256eee033939f3..5946a8610ab7b1 100644 --- a/examples/ota-provider-app/ota-provider-common/BdxOtaSender.cpp +++ b/examples/ota-provider-app/ota-provider-common/BdxOtaSender.cpp @@ -53,7 +53,7 @@ void BdxOtaSender::HandleTransferSessionOutput(TransferSession::OutputEvent & ev if (event.EventType != TransferSession::OutputEventType::kNone) { - ChipLogDetail(BDX, "OutputEvent type: %d", static_cast(event.EventType)); + ChipLogDetail(BDX, "OutputEvent type: %s", event.ToString(event.EventType)); } switch (event.EventType) diff --git a/examples/ota-requestor-app/ota-requestor-common/BDXDownloader.cpp b/examples/ota-requestor-app/ota-requestor-common/BDXDownloader.cpp index d3d9fd55bcd956..7dd9b33528a76d 100644 --- a/examples/ota-requestor-app/ota-requestor-common/BDXDownloader.cpp +++ b/examples/ota-requestor-app/ota-requestor-common/BDXDownloader.cpp @@ -40,7 +40,7 @@ void BdxDownloader::HandleTransferSessionOutput(TransferSession::OutputEvent & e if (event.EventType != TransferSession::OutputEventType::kNone) { - ChipLogDetail(BDX, "OutputEvent type: %d", static_cast(event.EventType)); + ChipLogDetail(BDX, "OutputEvent type: %s", event.ToString(event.EventType)); } switch (event.EventType) diff --git a/examples/ota-requestor-app/ota-requestor-common/ExampleOTARequestor.cpp b/examples/ota-requestor-app/ota-requestor-common/ExampleOTARequestor.cpp index 6805e2047911e0..edb85f1d718b6a 100644 --- a/examples/ota-requestor-app/ota-requestor-common/ExampleOTARequestor.cpp +++ b/examples/ota-requestor-app/ota-requestor-common/ExampleOTARequestor.cpp @@ -91,8 +91,16 @@ EmberAfStatus ExampleOTARequestor::HandleAnnounceOTAProvider( mProviderNodeId = providerLocation; mProviderFabricIndex = commandObj->GetExchangeContext()->GetSessionHandle().GetFabricIndex(); - ChipLogProgress(SoftwareUpdate, "Notified of Provider at NodeID: 0x" ChipLogFormatX64 " on FabricIndex 0x%" PRIu8, - ChipLogValueX64(mProviderNodeId), mProviderFabricIndex); + ChipLogProgress(SoftwareUpdate, "OTA Requestor received AnnounceOTAProvider"); + ChipLogDetail(SoftwareUpdate, " FabricIndex: %" PRIu8, mProviderFabricIndex); + ChipLogDetail(SoftwareUpdate, " ProviderNodeID: %" PRIu64, mProviderNodeId); + ChipLogDetail(SoftwareUpdate, " VendorID: %" PRIu16, commandData.vendorId); + ChipLogDetail(SoftwareUpdate, " AnnouncementReason: %" PRIu8, announcementReason); + if (commandData.metadataForNode.HasValue()) + { + ChipLogDetail(SoftwareUpdate, " MetadataForNode: %.*s", static_cast(commandData.metadataForNode.Value().size()), + commandData.metadataForNode.Value().data()); + } // If reason is URGENT_UPDATE_AVAILABLE, we start OTA immediately. Otherwise, respect the timer value set in mOtaStartDelayMs. // This is done to exemplify what a real-world OTA Requestor might do while also being configurable enough to use as a test app. diff --git a/src/app/clusters/ota-provider/ota-provider.cpp b/src/app/clusters/ota-provider/ota-provider.cpp index b058f14aab7ad2..9ffbc6693cbf8b 100644 --- a/src/app/clusters/ota-provider/ota-provider.cpp +++ b/src/app/clusters/ota-provider/ota-provider.cpp @@ -184,7 +184,15 @@ bool emberAfOtaSoftwareUpdateProviderClusterQueryImageCallback(app::CommandHandl return true; }; - ChipLogDetail(Zcl, "OTA Provider received QueryImage"); + ChipLogProgress(Zcl, "OTA Provider received QueryImage"); + ChipLogDetail(Zcl, " VendorID: %" PRIu16, vendorId); + ChipLogDetail(Zcl, " ProductID: %" PRIu16, productId); + ChipLogDetail(Zcl, " SoftwareVersion: %" PRIu32, softwareVersion); + ChipLogDetail(Zcl, " ProtocolsSupported: %" PRIu8, protocolsSupported); + ChipLogDetail(Zcl, " HardwareVersion: %" PRIu16, hardwareVersion); + ChipLogDetail(Zcl, " Location: %.*s", static_cast(location.size()), location.data()); + ChipLogDetail(Zcl, " RequestorCanConsent: %" PRIu8, requestorCanConsent); + ChipLogDetail(Zcl, " MetadataForProvider: %.*s", static_cast(metadataForProvider.size()), metadataForProvider.data()); if (location.size() != kLocationLen) { diff --git a/src/protocols/bdx/BdxTransferSession.cpp b/src/protocols/bdx/BdxTransferSession.cpp index a4b17ec736a848..f49248dbe1cdc3 100644 --- a/src/protocols/bdx/BdxTransferSession.cpp +++ b/src/protocols/bdx/BdxTransferSession.cpp @@ -774,6 +774,37 @@ bool TransferSession::IsTransferLengthDefinite() return (mTransferLength > 0); } +const char * TransferSession::OutputEvent::ToString(OutputEventType outputEventType) +{ + switch (outputEventType) + { + case OutputEventType::kNone: + return "None"; + case OutputEventType::kMsgToSend: + return "MsgToSend"; + case OutputEventType::kInitReceived: + return "InitReceived"; + case OutputEventType::kAcceptReceived: + return "AcceptReceived"; + case OutputEventType::kBlockReceived: + return "BlockReceived"; + case OutputEventType::kQueryReceived: + return "QueryReceived"; + case OutputEventType::kAckReceived: + return "AckReceived"; + case OutputEventType::kAckEOFReceived: + return "AckEOFReceived"; + case OutputEventType::kStatusReceived: + return "StatusReceived"; + case OutputEventType::kInternalError: + return "InternalError"; + case OutputEventType::kTransferTimeout: + return "TransferTimeout"; + default: + return "Unknown"; + } +} + TransferSession::OutputEvent TransferSession::OutputEvent::TransferInitEvent(TransferInitData data, System::PacketBufferHandle msg) { OutputEvent event(OutputEventType::kInitReceived); diff --git a/src/protocols/bdx/BdxTransferSession.h b/src/protocols/bdx/BdxTransferSession.h index 628a7d3e7aadc1..a889047a49a136 100644 --- a/src/protocols/bdx/BdxTransferSession.h +++ b/src/protocols/bdx/BdxTransferSession.h @@ -125,6 +125,8 @@ class DLL_EXPORT TransferSession OutputEvent() : EventType(OutputEventType::kNone) { statusData = { StatusCode::kNone }; } OutputEvent(OutputEventType type) : EventType(type) { statusData = { StatusCode::kNone }; } + const char * ToString(OutputEventType outputEventType); + static OutputEvent TransferInitEvent(TransferInitData data, System::PacketBufferHandle msg); static OutputEvent TransferAcceptEvent(TransferAcceptData data); static OutputEvent TransferAcceptEvent(TransferAcceptData data, System::PacketBufferHandle msg); From 2ec362107db26c630a26988a4542e4f4682926b5 Mon Sep 17 00:00:00 2001 From: Carol Yang Date: Sun, 31 Oct 2021 20:01:25 -0700 Subject: [PATCH 2/3] Use suggested format specifiers --- .../ota-requestor-common/ExampleOTARequestor.cpp | 4 ++-- src/app/clusters/ota-provider/ota-provider.cpp | 2 +- 2 files changed, 3 insertions(+), 3 deletions(-) diff --git a/examples/ota-requestor-app/ota-requestor-common/ExampleOTARequestor.cpp b/examples/ota-requestor-app/ota-requestor-common/ExampleOTARequestor.cpp index edb85f1d718b6a..c3566d331735f2 100644 --- a/examples/ota-requestor-app/ota-requestor-common/ExampleOTARequestor.cpp +++ b/examples/ota-requestor-app/ota-requestor-common/ExampleOTARequestor.cpp @@ -93,8 +93,8 @@ EmberAfStatus ExampleOTARequestor::HandleAnnounceOTAProvider( ChipLogProgress(SoftwareUpdate, "OTA Requestor received AnnounceOTAProvider"); ChipLogDetail(SoftwareUpdate, " FabricIndex: %" PRIu8, mProviderFabricIndex); - ChipLogDetail(SoftwareUpdate, " ProviderNodeID: %" PRIu64, mProviderNodeId); - ChipLogDetail(SoftwareUpdate, " VendorID: %" PRIu16, commandData.vendorId); + ChipLogDetail(SoftwareUpdate, " ProviderNodeID: 0x" ChipLogFormatX64, ChipLogValueX64(mProviderNodeId)); + ChipLogDetail(SoftwareUpdate, " VendorID: 0x%" PRIx16, commandData.vendorId); ChipLogDetail(SoftwareUpdate, " AnnouncementReason: %" PRIu8, announcementReason); if (commandData.metadataForNode.HasValue()) { diff --git a/src/app/clusters/ota-provider/ota-provider.cpp b/src/app/clusters/ota-provider/ota-provider.cpp index 9ffbc6693cbf8b..b526a9a7c01c8e 100644 --- a/src/app/clusters/ota-provider/ota-provider.cpp +++ b/src/app/clusters/ota-provider/ota-provider.cpp @@ -185,7 +185,7 @@ bool emberAfOtaSoftwareUpdateProviderClusterQueryImageCallback(app::CommandHandl }; ChipLogProgress(Zcl, "OTA Provider received QueryImage"); - ChipLogDetail(Zcl, " VendorID: %" PRIu16, vendorId); + ChipLogDetail(Zcl, " VendorID: 0x%" PRIx16, vendorId); ChipLogDetail(Zcl, " ProductID: %" PRIu16, productId); ChipLogDetail(Zcl, " SoftwareVersion: %" PRIu32, softwareVersion); ChipLogDetail(Zcl, " ProtocolsSupported: %" PRIu8, protocolsSupported); From 9b9725ded19dcf9e7c61b7bf6acf397f1b6d842f Mon Sep 17 00:00:00 2001 From: Carol Yang Date: Mon, 1 Nov 2021 09:59:19 -0700 Subject: [PATCH 3/3] Only print the size of TLV fields --- .../ota-requestor-common/ExampleOTARequestor.cpp | 3 +-- src/app/clusters/ota-provider/ota-provider.cpp | 2 +- 2 files changed, 2 insertions(+), 3 deletions(-) diff --git a/examples/ota-requestor-app/ota-requestor-common/ExampleOTARequestor.cpp b/examples/ota-requestor-app/ota-requestor-common/ExampleOTARequestor.cpp index c3566d331735f2..e3164884823c44 100644 --- a/examples/ota-requestor-app/ota-requestor-common/ExampleOTARequestor.cpp +++ b/examples/ota-requestor-app/ota-requestor-common/ExampleOTARequestor.cpp @@ -98,8 +98,7 @@ EmberAfStatus ExampleOTARequestor::HandleAnnounceOTAProvider( ChipLogDetail(SoftwareUpdate, " AnnouncementReason: %" PRIu8, announcementReason); if (commandData.metadataForNode.HasValue()) { - ChipLogDetail(SoftwareUpdate, " MetadataForNode: %.*s", static_cast(commandData.metadataForNode.Value().size()), - commandData.metadataForNode.Value().data()); + ChipLogDetail(SoftwareUpdate, " MetadataForNode: %zu", commandData.metadataForNode.Value().size()); } // If reason is URGENT_UPDATE_AVAILABLE, we start OTA immediately. Otherwise, respect the timer value set in mOtaStartDelayMs. diff --git a/src/app/clusters/ota-provider/ota-provider.cpp b/src/app/clusters/ota-provider/ota-provider.cpp index b526a9a7c01c8e..52855f003e1949 100644 --- a/src/app/clusters/ota-provider/ota-provider.cpp +++ b/src/app/clusters/ota-provider/ota-provider.cpp @@ -192,7 +192,7 @@ bool emberAfOtaSoftwareUpdateProviderClusterQueryImageCallback(app::CommandHandl ChipLogDetail(Zcl, " HardwareVersion: %" PRIu16, hardwareVersion); ChipLogDetail(Zcl, " Location: %.*s", static_cast(location.size()), location.data()); ChipLogDetail(Zcl, " RequestorCanConsent: %" PRIu8, requestorCanConsent); - ChipLogDetail(Zcl, " MetadataForProvider: %.*s", static_cast(metadataForProvider.size()), metadataForProvider.data()); + ChipLogDetail(Zcl, " MetadataForProvider: %zu", metadataForProvider.size()); if (location.size() != kLocationLen) {