Review feedback + some more prints.

src/app/CASESessionManager.cpp

@@ -45,7 +45,7 @@ CHIP_ERROR CASESessionManager::FindOrEstablishSession(PeerId peerId, Callback::C
 #endif
 
     ChipLogDetail(CASESessionManager,
-                  "FindOrEstablishSession: PeerId = CF" ChipLogFormatX64 ":N" ChipLogFormatX64 ", NodeIdWasResolved = %d",
+                  "FindOrEstablishSession: PeerId = " ChipLogFormatX64 ":" ChipLogFormatX64 ", NodeIdWasResolved = %d",
                   ChipLogValueX64(peerId.GetCompressedFabricId()), ChipLogValueX64(peerId.GetNodeId()), nodeIDWasResolved);
 
     OperationalDeviceProxy * session = FindExistingSession(peerId);

src/app/OperationalDeviceProxy.cpp

@@ -46,10 +46,9 @@ void OperationalDeviceProxy::MoveToState(State aTargetState)
 {
     if (mState != aTargetState)
     {
-        ChipLogDetail(Controller,
-                      "OperationalDeviceProxy[CF" ChipLogFormatX64 "-" ChipLogFormatX64 "]: Moving from state %d --> %d",
-                      ChipLogValueX64(mPeerId.GetCompressedFabricId()), ChipLogValueX64(mPeerId.GetNodeId()), (uint32_t) mState,
-                      (uint32_t) aTargetState);
+        ChipLogDetail(Controller, "OperationalDeviceProxy[" ChipLogFormatX64 ":" ChipLogFormatX64 "]: State change %d --> %d",
+                      ChipLogValueX64(mPeerId.GetCompressedFabricId()), ChipLogValueX64(mPeerId.GetNodeId()), to_underlying(mState),
+                      to_underlying(aTargetState));
         mState = aTargetState;
     }
 }

src/controller/AutoCommissioner.cpp

@@ -313,100 +313,6 @@ CHIP_ERROR AutoCommissioner::NOCChainGenerated(ByteSpan noc, ByteSpan icac, Byte
     return CHIP_NO_ERROR;
 }
 
-const char * AutoCommissioner::StageToString(CommissioningStage stage)
-{
-    switch (stage)
-    {
-    case kError:
-        return "Error";
-        break;
-
-    case kSecurePairing:
-        return "SecurePairing";
-        break;
-
-    case kArmFailsafe:
-        return "ArmFailSafe";
-        break;
-
-    case kGetNetworkTechnology:
-        return "GetNetworkTechnology";
-        break;
-
-    case kConfigRegulatory:
-        return "ConfigRegulatory";
-        break;
-
-    case kSendPAICertificateRequest:
-        return "SendPAICertificateRequest";
-        break;
-
-    case kSendDACCertificateRequest:
-        return "SendDACCertificateRequest";
-        break;
-
-    case kSendAttestationRequest:
-        return "SendAttestationRequest";
-        break;
-
-    case kAttestationVerification:
-        return "AttestationVerification";
-        break;
-
-    case kSendOpCertSigningRequest:
-        return "SendOpCertSigningRequest";
-        break;
-
-    case kGenerateNOCChain:
-        return "GenerateNOCChain";
-        break;
-
-    case kSendTrustedRootCert:
-        return "SendTrustedRootCert";
-        break;
-
-    case kSendNOC:
-        return "SendNOC";
-        break;
-
-    case kWiFiNetworkSetup:
-        return "WiFiNetworkSetup";
-        break;
-
-    case kThreadNetworkSetup:
-        return "ThreadNetworkSetup";
-        break;
-
-    case kWiFiNetworkEnable:
-        return "WiFiNetworkEnable";
-        break;
-
-    case kThreadNetworkEnable:
-        return "ThreadNetworkEnable";
-        break;
-
-    case kFindOperational:
-        return "FindOperational";
-        break;
-
-    case kSendComplete:
-        return "SendComplete";
-        break;
-
-    case kCleanup:
-        return "Cleanup";
-        break;
-
-    case kConfigACL:
-        return "ConfigACL";
-        break;
-
-    default:
-        return "???";
-        break;
-    }
-}
-
 CHIP_ERROR AutoCommissioner::CommissioningStepFinished(CHIP_ERROR err, CommissioningDelegate::CommissioningReport report)
 {
     if (err != CHIP_NO_ERROR)

src/controller/AutoCommissioner.h

@@ -36,7 +36,6 @@ class AutoCommissioner : public CommissioningDelegate
     virtual CHIP_ERROR StartCommissioning(DeviceCommissioner * commissioner, CommissioneeDeviceProxy * proxy) override;
 
     virtual CHIP_ERROR CommissioningStepFinished(CHIP_ERROR err, CommissioningDelegate::CommissioningReport report) override;
-    static const char * StageToString(CommissioningStage stage);
 
 private:
     CommissioningStage GetNextCommissioningStage(CommissioningStage currentStage, CHIP_ERROR & lastErr);

src/controller/BUILD.gn

@@ -46,6 +46,7 @@ static_library("controller") {
       "CommissioneeDeviceProxy.h",
       "CommissionerDiscoveryController.cpp",
       "CommissionerDiscoveryController.h",
+      "CommissioningDelegate.cpp",
       "DeviceDiscoveryDelegate.h",
       "EmptyDataModelHandler.cpp",
       "ExampleOperationalCredentialsIssuer.cpp",

src/controller/CHIPDeviceController.cpp

@@ -1446,8 +1446,10 @@ void DeviceCommissioner::CommissioningStageComplete(CHIP_ERROR err, Commissionin
 
 void DeviceCommissioner::OnOperationalNodeResolved(const chip::Dnssd::ResolvedNodeData & nodeData)
 {
-    ChipLogProgress(Controller, "F" ChipLogFormatX64 ": OperationalDiscoveryComplete for device ID N" ChipLogFormatX64,
-                    ChipLogValueX64(mFabricId), ChipLogValueX64(nodeData.mPeerId.GetNodeId()));
+    ChipLogProgress(Controller,
+                    "[" ChipLogFormatX64 "] OperationalDiscoveryComplete for device " ChipLogFormatX64 ":" ChipLogFormatX64,
+                    ChipLogValueX64(mFabricId), ChipLogValueX64(nodeData.mPeerId.GetCompressedFabricId()),
+                    ChipLogValueX64(nodeData.mPeerId.GetNodeId()));
     VerifyOrReturn(mState == State::Initialized);
 
     // TODO: minimal mdns is buggy and violates the API contract for the
@@ -1751,8 +1753,8 @@ void DeviceCommissioner::PerformCommissioningStep(DeviceProxy * proxy, Commissio
                                                   CommissioningDelegate * delegate, EndpointId endpoint,
                                                   Optional<System::Clock::Timeout> timeout)
 {
-    ChipLogProgress(Controller, "Performing next commissioning step '%s' with completion status = '%s'",
-                    AutoCommissioner::StageToString(step), params.GetCompletionStatus().AsString());
+    ChipLogProgress(Controller, "Performing next commissioning step '%s' with completion status = '%s'", StageToString(step),
+                    params.GetCompletionStatus().AsString());
 
     // For now, we ignore errors coming in from the device since not all commissioning clusters are implemented on the device
     // side.
@@ -1998,7 +2000,6 @@ void DeviceCommissioner::PerformCommissioningStep(DeviceProxy * proxy, Commissio
             CommissioningStageComplete(CHIP_ERROR_INVALID_ARGUMENT);
             return;
         }
-        ChipLogProgress(Controller, "Sending operational certificate chain to the device");
         SendOperationalCertificate(proxy, params.GetNoc().Value(), params.GetIcac().Value(), params.GetIpk().Value(),
                                    params.GetAdminSubject().Value());
         break;
@@ -2013,7 +2014,6 @@ void DeviceCommissioner::PerformCommissioningStep(DeviceProxy * proxy, Commissio
             return;
         }
 
-        ChipLogProgress(Controller, "Adding wifi network");
         NetworkCommissioning::Commands::AddOrUpdateWiFiNetwork::Type request;
         request.ssid        = params.GetWiFiCredentials().Value().ssid;
         request.credentials = params.GetWiFiCredentials().Value().credentials;
@@ -2028,7 +2028,6 @@ void DeviceCommissioner::PerformCommissioningStep(DeviceProxy * proxy, Commissio
             CommissioningStageComplete(CHIP_ERROR_INVALID_ARGUMENT);
             return;
         }
-        ChipLogProgress(Controller, "Adding thread network");
         NetworkCommissioning::Commands::AddOrUpdateThreadNetwork::Type request;
         request.operationalDataset = params.GetThreadOperationalDataset().Value();
         request.breadcrumb         = breadcrumb;
@@ -2042,7 +2041,6 @@ void DeviceCommissioner::PerformCommissioningStep(DeviceProxy * proxy, Commissio
             CommissioningStageComplete(CHIP_ERROR_INVALID_ARGUMENT);
             return;
         }
-        ChipLogProgress(Controller, "Enabling wifi network");
         NetworkCommissioning::Commands::ConnectNetwork::Type request;
         request.networkID  = params.GetWiFiCredentials().Value().ssid;
         request.breadcrumb = breadcrumb;
@@ -2060,7 +2058,6 @@ void DeviceCommissioner::PerformCommissioningStep(DeviceProxy * proxy, Commissio
             CommissioningStageComplete(CHIP_ERROR_INVALID_ARGUMENT);
             return;
         }
-        ChipLogProgress(Controller, "Enabling thread network");
         NetworkCommissioning::Commands::ConnectNetwork::Type request;
         request.networkID  = extendedPanId;
         request.breadcrumb = breadcrumb;
@@ -2078,14 +2075,12 @@ void DeviceCommissioner::PerformCommissioningStep(DeviceProxy * proxy, Commissio
     }
     break;
     case CommissioningStage::kSendComplete: {
-        ChipLogProgress(Controller, "Calling commissioning complete");
         GeneralCommissioning::Commands::CommissioningComplete::Type request;
         SendCommand<NetworkCommissioningCluster>(proxy, request, OnCommissioningCompleteResponse, OnBasicFailure, endpoint,
                                                  timeout);
     }
     break;
     case CommissioningStage::kCleanup:
-        ChipLogProgress(Controller, "Rendezvous cleanup");
         if (mPairingDelegate != nullptr)
         {
             mPairingDelegate->OnCommissioningComplete(proxy->GetDeviceId(), params.GetCompletionStatus());

src/controller/CommissioningDelegate.cpp

@@ -0,0 +1,115 @@
+/*
+ *
+ *    Copyright (c) 2021 Project CHIP Authors
+ *    All rights reserved.
+ *
+ *    Licensed under the Apache License, Version 2.0 (the "License");
+ *    you may not use this file except in compliance with the License.
+ *    You may obtain a copy of the License at
+ *
+ *        http://www.apache.org/licenses/LICENSE-2.0
+ *
+ *    Unless required by applicable law or agreed to in writing, software
+ *    distributed under the License is distributed on an "AS IS" BASIS,
+ *    WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied.
+ *    See the License for the specific language governing permissions and
+ *    limitations under the License.
+ */
+
+#include <controller/CommissioningDelegate.h>
+
+namespace chip {
+namespace Controller {
+
+const char * StageToString(CommissioningStage stage)
+{
+    switch (stage)
+    {
+    case kError:
+        return "Error";
+        break;
+
+    case kSecurePairing:
+        return "SecurePairing";
+        break;
+
+    case kArmFailsafe:
+        return "ArmFailSafe";
+        break;
+
+    case kConfigRegulatory:
+        return "ConfigRegulatory";
+        break;
+
+    case kSendPAICertificateRequest:
+        return "SendPAICertificateRequest";
+        break;
+
+    case kSendDACCertificateRequest:
+        return "SendDACCertificateRequest";
+        break;
+
+    case kSendAttestationRequest:
+        return "SendAttestationRequest";
+        break;
+
+    case kAttestationVerification:
+        return "AttestationVerification";
+        break;
+
+    case kSendOpCertSigningRequest:
+        return "SendOpCertSigningRequest";
+        break;
+
+    case kGenerateNOCChain:
+        return "GenerateNOCChain";
+        break;
+
+    case kSendTrustedRootCert:
+        return "SendTrustedRootCert";
+        break;
+
+    case kSendNOC:
+        return "SendNOC";
+        break;
+
+    case kWiFiNetworkSetup:
+        return "WiFiNetworkSetup";
+        break;
+
+    case kThreadNetworkSetup:
+        return "ThreadNetworkSetup";
+        break;
+
+    case kWiFiNetworkEnable:
+        return "WiFiNetworkEnable";
+        break;
+
+    case kThreadNetworkEnable:
+        return "ThreadNetworkEnable";
+        break;
+
+    case kFindOperational:
+        return "FindOperational";
+        break;
+
+    case kSendComplete:
+        return "SendComplete";
+        break;
+
+    case kCleanup:
+        return "Cleanup";
+        break;
+
+    case kConfigACL:
+        return "ConfigACL";
+        break;
+
+    default:
+        return "???";
+        break;
+    }
+}
+
+} // namespace Controller
+} // namespace chip

src/controller/CommissioningDelegate.h

@@ -55,6 +55,8 @@ enum CommissioningStage : uint8_t
     kConfigACL,
 };
 
+const char * StageToString(CommissioningStage stage);
+
 struct WiFiCredentials
 {
     ByteSpan ssid;

src/lib/dnssd/Discovery_ImplPlatform.cpp

@@ -643,6 +643,10 @@ Resolver & chip::Dnssd::Resolver::Instance()
 CHIP_ERROR ResolverProxy::ResolveNodeId(const PeerId & peerId, Inet::IPAddressType type)
 {
     VerifyOrReturnError(mDelegate != nullptr, CHIP_ERROR_INCORRECT_STATE);
+
+    ChipLogProgress(Discovery, "Resolving " ChipLogFormatX64 ":" ChipLogFormatX64 " ...",
+                    ChipLogValueX64(peerId.GetCompressedFabricId()), ChipLogValueX64(peerId.GetNodeId()));
+
     mDelegate->Retain();
 
     DnssdService service;

src/lib/dnssd/Resolver.h

@@ -73,7 +73,8 @@ struct ResolvedNodeData
 
         // Would be nice to log the interface id, but sorting out how to do so
         // across our differnet InterfaceId implementations is a pain.
-        ChipLogProgress(Discovery, "Node ID resolved for 0x" ChipLogFormatX64, ChipLogValueX64(mPeerId.GetNodeId()));
+        ChipLogProgress(Discovery, "Node ID resolved for " ChipLogFormatX64 ":" ChipLogFormatX64,
+                        ChipLogValueX64(mPeerId.GetCompressedFabricId()), ChipLogValueX64(mPeerId.GetNodeId()));
         for (unsigned i = 0; i < mNumIPs; ++i)
         {
             mAddress[i].ToString(addrBuffer);

src/lib/dnssd/Resolver_ImplMinimalMdns.cpp

@@ -691,6 +691,9 @@ Resolver & chip::Dnssd::Resolver::Instance()
 CHIP_ERROR ResolverProxy::ResolveNodeId(const PeerId & peerId, Inet::IPAddressType type)
 {
     VerifyOrReturnError(mDelegate != nullptr, CHIP_ERROR_INCORRECT_STATE);
+
+    ChipLogProgress(Discovery, "Resolving " ChipLogFormatX64 ":" ChipLogFormatX64 " ...",
+                    ChipLogValueX64(peerId.GetCompressedFabricId()), ChipLogValueX64(peerId.GetNodeId()));
     chip::Dnssd::Resolver::Instance().SetOperationalDelegate(mDelegate);
     return chip::Dnssd::Resolver::Instance().ResolveNodeId(peerId, type);
 }