[DO-NOT-MERGE-TO-MAINLINE] This change is already in master branch th…

…at fixes DNS-SD browsing

Add an API to stop a DNS-SD browse operation. (project-chip#22823)

* Add an API to stop a DNS-SD browse operation.

Most backends don't implement this yet. Darwin does, and no longer
stops Browse operations itself.

Fixes project-chip#19194

May provide a way toward fixing
project-chip#13275

* Address review comments.

* Address more review comments.

[darwin] Use DNSServiceReconfirmRecord for A and AAAA records to miti… (project-chip#23067)

* [Dnssd] Add ReconfirmRecord method to verify address that appears to be out of date

* [SetUpCodePairer] Ask Dnssd to reconfirm discovered addresses if connecting to them ends with a CHIP_ERROR_TIMEOUT

Fix Logging When Trying to Log Nullptr To Strings (project-chip#23604)

This PR attempts to identify all cases where %s specifiers in the logging APIs
(ChipLogError(), ChipLogProgress(), ChipLogDetail()) don't have a guaranteed
non-null string parameter.

In all identified cases the issue is fixed using StringOrNullMarker() helper
method to guarantee it doesn't happen.

Use the "right" byte-swapping function for port in Darwin DnssdImpl. (project-chip#23894)

The incoming port is in host byte order and we are converting to network byte
order, so should use htons (which happens to do the same thing as ntohs, so no
behavior change).

Co-authored-by: Andrei Litvin <[email protected]>

Add a way for Resolver consumers to cancel operational resolve attempts. (project-chip#24010)

* Add a way for Resolver consumers to cancel operational resolve attempts.

Adds a way for consumers to notify Resolver when they no longer care
about an operational resolve, so a Resolver implementation can keep
track of how many consumers are interested and stop work as desired if
no one is interested.

Fixes project-chip#23881

* Address review comments.

* Address review comments.

Make sure we stop resolves triggered by a browse when the browse stops on Darwin. (project-chip#24733)

* Make sure we stop resolves triggered by a browse when the browse stops on Darwin.

Without this change, if there is a PTR record that matches whatever we are
browsing but no corresponding SRV record, we would end up leaking a resolve
forever.

Tested by modifying minimal mdns SrvResponder::AddAllResponses to no-op instead
of actually adding any responses, then trying to commission the device running
the modified minimal mdns.  Without this change, when the browse stops the
resolves it triggered keep going.  With this change, termination of the browse
also terminates the resolves.

Fixes project-chip#24074

* Also avoid leaking ResolveContext instances.

* Fix handling of multiple interfaces.

* Address review comment.

Improve discovery logging on Darwin. (project-chip#24846)

1) Use progress, not detail, logging, because detail logging is not actually
   persisted in system logs.
2) Add logging to a few functions that were missing it.

Remove the address type argument from ResolveNodeId. (project-chip#24006)

All consumers were passing kAny in practice, and some of the backends
(e.g. minimal mdns) had no capability to filter by type anyway.

examples/chip-tool/commands/pairing/PairingCommand.cpp

@@ -237,7 +237,8 @@ void PairingCommand::OnDiscoveredDevice(const chip::Dnssd::DiscoveredNodeData &
     nodeData.resolutionData.ipAddress[0].ToString(buf);
     ChipLogProgress(chipTool, "Discovered Device: %s:%u", buf, port);
 
-    // Stop Mdns discovery. Is it the right method ?
+    // Stop Mdns discovery.
+    CurrentCommissioner().StopCommissionableDiscovery();
     CurrentCommissioner().RegisterDeviceDiscoveryDelegate(nullptr);
 
     Inet::InterfaceId interfaceId =

src/app/tests/suites/commands/discovery/DiscoveryCommands.cpp

@@ -125,6 +125,7 @@ CHIP_ERROR DiscoveryCommands::SetupDiscoveryCommands()
 
 CHIP_ERROR DiscoveryCommands::TearDownDiscoveryCommands()
 {
+    mDNSResolver.StopDiscovery();
     mDNSResolver.SetOperationalDelegate(nullptr);
     mDNSResolver.SetCommissioningDelegate(nullptr);
     return CHIP_NO_ERROR;

src/app/tests/suites/credentials/TestHarnessDACProvider.cpp

@@ -122,15 +122,15 @@ void TestHarnessDACProvider::Init(const char * filepath)
     std::ifstream json(filepath, std::ifstream::binary);
     if (!json)
     {
-        ChipLogError(AppServer, "Error opening json file: %s", filepath);
+        ChipLogError(AppServer, "Error opening json file: %s", StringOrNullMarker(filepath));
         return;
     }
 
     Json::Reader reader;
     Json::Value root;
     if (!reader.parse(json, root))
     {
-        ChipLogError(AppServer, "Error parsing json file: %s", filepath);
+        ChipLogError(AppServer, "Error parsing json file: %s", StringOrNullMarker(filepath));
         return;
     }
 

src/app/tests/suites/include/ConstraintsChecker.h

@@ -46,7 +46,8 @@ class ConstraintsChecker
 
     bool CheckConstraintFormat(const char * itemName, const char * current, const char * expected)
     {
-        ChipLogError(chipTool, "Warning: %s format checking is not implemented yet. Expected format: '%s'", itemName, expected);
+        ChipLogError(chipTool, "Warning: %s format checking is not implemented yet. Expected format: '%s'",
+                     StringOrNullMarker(itemName), StringOrNullMarker(expected));
         return true;
     }
 

src/app/tests/suites/include/PICSChecker.h

@@ -40,7 +40,7 @@ class PICSChecker
         bool shouldSkip = !PICSBooleanExpressionParser::Eval(expression, pics);
         if (shouldSkip)
         {
-            ChipLogProgress(chipTool, " **** Skipping: %s == false\n", expression);
+            ChipLogProgress(chipTool, " **** Skipping: %s == false\n", StringOrNullMarker(expression));
         }
         return shouldSkip;
     }

src/app/tests/suites/include/TestRunner.h

@@ -30,11 +30,11 @@ class TestRunner
     TestRunner(const char * name, uint16_t testCount) : mTestName(name), mTestCount(testCount), mTestIndex(0) {}
     virtual ~TestRunner(){};
 
-    void LogStart() { ChipLogProgress(chipTool, " ***** Test Start : %s\n", mTestName); }
+    void LogStart() { ChipLogProgress(chipTool, " ***** Test Start : %s\n", StringOrNullMarker(mTestName)); }
 
     void LogStep(uint32_t stepNumber, const char * stepName)
     {
-        ChipLogProgress(chipTool, " ***** Test Step %u : %s\n", stepNumber, stepName);
+        ChipLogProgress(chipTool, " ***** Test Step %u : %s\n", stepNumber, StringOrNullMarker(stepName));
     }
 
     void LogEnd(std::string message, CHIP_ERROR err)

src/controller/CHIPDeviceController.cpp

@@ -1431,6 +1431,11 @@ CHIP_ERROR DeviceCommissioner::DiscoverCommissionableNodes(Dnssd::DiscoveryFilte
     return mDNSResolver.DiscoverCommissionableNodes(filter);
 }
 
+CHIP_ERROR DeviceCommissioner::StopCommissionableDiscovery()
+{
+    return mDNSResolver.StopDiscovery();
+}
+
 const Dnssd::DiscoveredNodeData * DeviceCommissioner::GetDiscoveredDevice(int idx)
 {
     return GetDiscoveredNode(idx);

src/controller/CHIPDeviceController.h

@@ -597,6 +597,12 @@ class DLL_EXPORT DeviceCommissioner : public DeviceController,
      */
     CHIP_ERROR DiscoverCommissionableNodes(Dnssd::DiscoveryFilter filter);
 
+    /**
+     * Stop commissionable discovery triggered by a previous
+     * DiscoverCommissionableNodes call.
+     */
+    CHIP_ERROR StopCommissionableDiscovery();
+
     /**
      * @brief
      *   Returns information about discovered devices.

src/controller/SetUpCodePairer.cpp

@@ -187,6 +187,8 @@ CHIP_ERROR SetUpCodePairer::StopConnectOverIP()
 
     mWaitingForDiscovery[kIPTransport] = false;
     currentFilter.type                 = Dnssd::DiscoveryFilterType::kNone;
+
+    mCommissioner->StopCommissionableDiscovery();
     return CHIP_NO_ERROR;
 }
 
@@ -216,7 +218,7 @@ bool SetUpCodePairer::ConnectToDiscoveredDevice()
         // Remove it from the queue before we try to connect, in case the
         // connection attempt fails and calls right back into us to try the next
         // thing.
-        RendezvousParameters params(mDiscoveredParameters.front());
+        SetUpCodePairerParameters params(mDiscoveredParameters.front());
         mDiscoveredParameters.pop();
 
         params.SetSetupPINCode(mSetUpPINCode);
@@ -230,6 +232,11 @@ bool SetUpCodePairer::ConnectToDiscoveredDevice()
         // Handle possibly-sync call backs from attempts to establish PASE.
         ExpectPASEEstablishment();
 
+        if (params.GetPeerAddress().GetTransportType() == Transport::Type::kUdp)
+        {
+            mCurrentPASEParameters.SetValue(params);
+        }
+
         CHIP_ERROR err;
         if (mConnectionType == SetupCodePairerBehaviour::kCommission)
         {
@@ -260,9 +267,7 @@ void SetUpCodePairer::OnDiscoveredDeviceOverBle(BLE_CONNECTION_OBJECT connObj)
 
     mWaitingForDiscovery[kBLETransport] = false;
 
-    Transport::PeerAddress peerAddress = Transport::PeerAddress::BLE();
-    mDiscoveredParameters.emplace();
-    mDiscoveredParameters.back().SetPeerAddress(peerAddress).SetConnectionObject(connObj);
+    mDiscoveredParameters.emplace(connObj);
     ConnectToDiscoveredDevice();
 }
 
@@ -316,7 +321,7 @@ void SetUpCodePairer::NotifyCommissionableDeviceDiscovered(const Dnssd::Discover
         nodeData.resolutionData.ipAddress[0].IsIPv6LinkLocal() ? nodeData.resolutionData.interfaceId : Inet::InterfaceId::Null();
     Transport::PeerAddress peerAddress =
         Transport::PeerAddress::UDP(nodeData.resolutionData.ipAddress[0], nodeData.resolutionData.port, interfaceId);
-    mDiscoveredParameters.emplace();
+    mDiscoveredParameters.emplace(nodeData.resolutionData);
     mDiscoveredParameters.back().SetPeerAddress(peerAddress);
     ConnectToDiscoveredDevice();
 }
@@ -373,6 +378,7 @@ void SetUpCodePairer::ResetDiscoveryState()
         mDiscoveredParameters.pop();
     }
 
+    mCurrentPASEParameters.ClearValue();
     mLastPASEError = CHIP_NO_ERROR;
 }
 
@@ -449,6 +455,21 @@ void SetUpCodePairer::OnPairingComplete(CHIP_ERROR error)
         return;
     }
 
+    // It may happen that there is a stale DNS entry. If so, ReconfirmRecord will flush
+    // the record from the daemon cache once it determines that it is invalid.
+    // It may not help for this particular resolve, but may help subsequent resolves.
+    if (CHIP_ERROR_TIMEOUT == error && mCurrentPASEParameters.HasValue())
+    {
+        const auto & params = mCurrentPASEParameters.Value();
+        auto & ip           = params.GetPeerAddress().GetIPAddress();
+        auto err            = Dnssd::Resolver::Instance().ReconfirmRecord(params.mHostName, ip, params.mInterfaceId);
+        if (CHIP_NO_ERROR != err && CHIP_ERROR_NOT_IMPLEMENTED != err)
+        {
+            ChipLogError(Controller, "Error when verifying the validity of an address: %" CHIP_ERROR_FORMAT, err.Format());
+        }
+    }
+    mCurrentPASEParameters.ClearValue();
+
     // We failed to establish PASE.  Try the next thing we have discovered, if
     // any.
     if (TryNextRendezvousParameters())
@@ -502,5 +523,32 @@ void SetUpCodePairer::OnDeviceDiscoveredTimeoutCallback(System::Layer * layer, v
     }
 }
 
+SetUpCodePairerParameters::SetUpCodePairerParameters(const Dnssd::CommonResolutionData & data)
+{
+    mInterfaceId = data.interfaceId;
+    Platform::CopyString(mHostName, data.hostName);
+
+    auto & ip = data.ipAddress[0];
+    SetPeerAddress(Transport::PeerAddress::UDP(ip, data.port, ip.IsIPv6LinkLocal() ? data.interfaceId : Inet::InterfaceId::Null()));
+
+    // if (data.mrpRetryIntervalIdle.HasValue())
+    // {
+    //     SetIdleInterval(data.mrpRetryIntervalIdle.Value());
+    // }
+
+    // if (data.mrpRetryIntervalActive.HasValue())
+    // {
+    //     SetActiveInterval(data.mrpRetryIntervalActive.Value());
+    // }
+}
+
+#if CONFIG_NETWORK_LAYER_BLE
+SetUpCodePairerParameters::SetUpCodePairerParameters(BLE_CONNECTION_OBJECT connObj)
+{
+    Transport::PeerAddress peerAddress = Transport::PeerAddress::BLE();
+    SetPeerAddress(peerAddress).SetConnectionObject(connObj);
+}
+#endif // CONFIG_NETWORK_LAYER_BLE
+
 } // namespace Controller
 } // namespace chip

src/controller/SetUpCodePairer.h

@@ -48,6 +48,17 @@ namespace Controller {
 
 class DeviceCommissioner;
 
+class SetUpCodePairerParameters : public RendezvousParameters
+{
+public:
+    SetUpCodePairerParameters(const Dnssd::CommonResolutionData & data);
+#if CONFIG_NETWORK_LAYER_BLE
+    SetUpCodePairerParameters(BLE_CONNECTION_OBJECT connObj);
+#endif // CONFIG_NETWORK_LAYER_BLE
+    char mHostName[Dnssd::kHostNameMaxLength + 1] = {};
+    Inet::InterfaceId mInterfaceId;
+};
+
 enum class SetupCodePairerBehaviour : uint8_t
 {
     kCommission,
@@ -172,7 +183,12 @@ class DLL_EXPORT SetUpCodePairer : public DevicePairingDelegate
     // Queue of things we have discovered but not tried connecting to yet.  The
     // general discovery/pairing process will terminate once this queue is empty
     // and all the booleans in mWaitingForDiscovery are false.
-    std::queue<RendezvousParameters> mDiscoveredParameters;
+    std::queue<SetUpCodePairerParameters> mDiscoveredParameters;
+
+    // Current thing we are trying to connect to over UDP. If a PASE connection fails with
+    // a CHIP_ERROR_TIMEOUT, the discovered parameters will be used to ask the
+    // mdns daemon to invalidate the
+    Optional<SetUpCodePairerParameters> mCurrentPASEParameters;
 
     // mWaitingForPASE is true if we have called either
     // EstablishPASEConnection or PairDevice on mCommissioner and are now just

src/controller/java/AndroidDeviceControllerWrapper.cpp

@@ -648,7 +648,7 @@ void AndroidDeviceControllerWrapper::OnScanNetworksFailure(CHIP_ERROR error)
 
 CHIP_ERROR AndroidDeviceControllerWrapper::SyncGetKeyValue(const char * key, void * value, uint16_t & size)
 {
-    ChipLogProgress(chipTool, "KVS: Getting key %s", key);
+    ChipLogProgress(chipTool, "KVS: Getting key %s", StringOrNullMarker(key));
 
     size_t read_size = 0;
 
@@ -661,12 +661,12 @@ CHIP_ERROR AndroidDeviceControllerWrapper::SyncGetKeyValue(const char * key, voi
 
 CHIP_ERROR AndroidDeviceControllerWrapper::SyncSetKeyValue(const char * key, const void * value, uint16_t size)
 {
-    ChipLogProgress(chipTool, "KVS: Setting key %s", key);
+    ChipLogProgress(chipTool, "KVS: Setting key %s", StringOrNullMarker(key));
     return chip::DeviceLayer::PersistedStorage::KeyValueStoreMgr().Put(key, value, size);
 }
 
 CHIP_ERROR AndroidDeviceControllerWrapper::SyncDeleteKeyValue(const char * key)
 {
-    ChipLogProgress(chipTool, "KVS: Deleting key %s", key);
+    ChipLogProgress(chipTool, "KVS: Deleting key %s", StringOrNullMarker(key));
     return chip::DeviceLayer::PersistedStorage::KeyValueStoreMgr().Delete(key);
 }

src/controller/python/ChipDeviceController-StorageDelegate.cpp

@@ -1,7 +1,6 @@
-
 /*
  *
- *    Copyright (c) 2021 Project CHIP Authors
+ *    Copyright (c) 2021-2022 Project CHIP Authors
  *    All rights reserved.
  *
  *    Licensed under the Apache License, Version 2.0 (the "License");
@@ -58,7 +57,7 @@ CHIP_ERROR PythonPersistentStorageDelegate::SyncGetKeyValue(const char * key, vo
 CHIP_ERROR PythonPersistentStorageDelegate::SyncSetKeyValue(const char * key, const void * value, uint16_t size)
 {
     mStorage[key] = std::string(static_cast<const char *>(value), size);
-    ChipLogDetail(Controller, "SyncSetKeyValue on %s", key);
+    ChipLogDetail(Controller, "SyncSetKeyValue on %s", StringOrNullMarker(key));
 
     return CHIP_NO_ERROR;
 }
@@ -79,7 +78,7 @@ namespace Python {
 
 CHIP_ERROR StorageAdapter::SyncGetKeyValue(const char * key, void * value, uint16_t & size)
 {
-    ChipLogDetail(Controller, "StorageAdapter::GetKeyValue: Key = %s, Value = %p (%u)", key, value, size);
+    ChipLogDetail(Controller, "StorageAdapter::GetKeyValue: Key = %s, Value = %p (%u)", StringOrNullMarker(key), value, size);
     if ((value == nullptr) && (size != 0))
     {
         return CHIP_ERROR_INVALID_ARGUMENT;
@@ -109,7 +108,7 @@ CHIP_ERROR StorageAdapter::SyncGetKeyValue(const char * key, void * value, uint1
 CHIP_ERROR StorageAdapter::SyncSetKeyValue(const char * key, const void * value, uint16_t size)
 {
     ReturnErrorCodeIf(((value == nullptr) && (size != 0)), CHIP_ERROR_INVALID_ARGUMENT);
-    ChipLogDetail(Controller, "StorageAdapter::SetKeyValue: Key = %s, Value = %p (%u)", key, value, size);
+    ChipLogDetail(Controller, "StorageAdapter::SetKeyValue: Key = %s, Value = %p (%u)", StringOrNullMarker(key), value, size);
     mSetKeyCb(mContext, key, value, size);
     return CHIP_NO_ERROR;
 }
@@ -124,7 +123,7 @@ CHIP_ERROR StorageAdapter::SyncDeleteKeyValue(const char * key)
         return err;
     }
 
-    ChipLogDetail(Controller, "StorageAdapter::DeleteKeyValue: Key = %s", key);
+    ChipLogDetail(Controller, "StorageAdapter::DeleteKeyValue: Key = %s", StringOrNullMarker(key));
     mDeleteKeyCb(mContext, key);
     return CHIP_NO_ERROR;
 }

src/controller/python/chip/discovery/NodeResolution.cpp

@@ -38,6 +38,7 @@ class PythonResolverDelegate : public OperationalResolveDelegate
 public:
     void OnOperationalNodeResolved(const ResolvedNodeData & nodeData) override
     {
+        Resolver::Instance().NodeIdResolutionNoLongerNeeded(nodeData.operationalData.peerId);
         if (mSuccessCallback != nullptr)
         {
             char ipAddressBuffer[128];
@@ -60,6 +61,7 @@ class PythonResolverDelegate : public OperationalResolveDelegate
 
     void OnOperationalNodeResolutionFailed(const PeerId & peerId, CHIP_ERROR error) override
     {
+        Resolver::Instance().NodeIdResolutionNoLongerNeeded(peerId);
         if (mFailureCallback != nullptr)
         {
             mFailureCallback(peerId.GetCompressedFabricId(), peerId.GetNodeId(), error.AsInteger());
@@ -97,8 +99,7 @@ extern "C" ChipError::StorageType pychip_discovery_resolve(uint64_t fabricId, ui
         ReturnOnFailure(result);
         Resolver::Instance().SetOperationalDelegate(&gPythonResolverDelegate);
 
-        result = Resolver::Instance().ResolveNodeId(chip::PeerId().SetCompressedFabricId(fabricId).SetNodeId(nodeId),
-                                                    chip::Inet::IPAddressType::kAny);
+        result = Resolver::Instance().ResolveNodeId(chip::PeerId().SetCompressedFabricId(fabricId).SetNodeId(nodeId));
     });
 
     return result.AsInteger();

src/controller/tests/TestCommissionableNodeController.cpp

@@ -35,12 +35,18 @@ class MockResolver : public Resolver
     void Shutdown() override {}
     void SetOperationalDelegate(OperationalResolveDelegate * delegate) override {}
     void SetCommissioningDelegate(CommissioningResolveDelegate * delegate) override {}
-    CHIP_ERROR ResolveNodeId(const PeerId & peerId, Inet::IPAddressType type) override { return ResolveNodeIdStatus; }
+    void NodeIdResolutionNoLongerNeeded(const PeerId & peerId) override {}
+    CHIP_ERROR ResolveNodeId(const PeerId & peerId) override { return ResolveNodeIdStatus; }
     CHIP_ERROR DiscoverCommissioners(DiscoveryFilter filter = DiscoveryFilter()) override { return DiscoverCommissionersStatus; }
     CHIP_ERROR DiscoverCommissionableNodes(DiscoveryFilter filter = DiscoveryFilter()) override
     {
         return CHIP_ERROR_NOT_IMPLEMENTED;
     }
+    CHIP_ERROR StopDiscovery() override { return CHIP_ERROR_NOT_IMPLEMENTED; }
+    CHIP_ERROR ReconfirmRecord(const char * hostname, Inet::IPAddress address, Inet::InterfaceId interfaceId) override
+    {
+        return CHIP_ERROR_NOT_IMPLEMENTED;
+    }
 
     CHIP_ERROR InitStatus                  = CHIP_NO_ERROR;
     CHIP_ERROR ResolveNodeIdStatus         = CHIP_NO_ERROR;

src/credentials/LastKnownGoodTime.cpp

@@ -44,7 +44,7 @@ void LastKnownGoodTime::LogTime(const char * msg, System::Clock::Seconds32 chipE
     uint8_t second;
     ChipEpochToCalendarTime(chipEpochTime.count(), year, month, day, hour, minute, second);
     snprintf(buf, sizeof(buf), "%04u-%02u-%02uT%02u:%02u:%02u", year, month, day, hour, minute, second);
-    ChipLogProgress(TimeService, "%s%s", msg, buf);
+    ChipLogProgress(TimeService, "%s%s", StringOrNullMarker(msg), buf);
 }
 
 CHIP_ERROR LastKnownGoodTime::LoadLastKnownGoodChipEpochTime(System::Clock::Seconds32 & lastKnownGoodChipEpochTime) const

src/crypto/CHIPCryptoPALOpenSSL.cpp

@@ -115,7 +115,8 @@ static void _logSSLError()
         const char * err_str_reason  = ERR_reason_error_string(static_cast<libssl_err_type>(ssl_err_code));
         if (err_str_lib)
         {
-            ChipLogError(Crypto, " ssl err  %s %s %s\n", err_str_lib, err_str_routine, err_str_reason);
+            ChipLogError(Crypto, " ssl err  %s %s %s\n", StringOrNullMarker(err_str_lib), StringOrNullMarker(err_str_routine),
+                         StringOrNullMarker(err_str_reason));
         }
 #endif // CHIP_ERROR_LOGGING
         ssl_err_code = ERR_get_error();