From 32ecfc0d9ec816d6e133654be878b1a23b07f829 Mon Sep 17 00:00:00 2001 From: Boris Zbarsky Date: Fri, 3 Feb 2023 12:23:27 -0500 Subject: [PATCH] Improve discovery logging on Darwin. (#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. --- src/platform/Darwin/DnssdContexts.cpp | 16 +++++------ .../Darwin/DnssdHostNameRegistrar.cpp | 28 +++++++++---------- src/platform/Darwin/DnssdImpl.cpp | 25 ++++++++++------- 3 files changed, 37 insertions(+), 32 deletions(-) diff --git a/src/platform/Darwin/DnssdContexts.cpp b/src/platform/Darwin/DnssdContexts.cpp index f6052669d91853..ebc1079b3fb32b 100644 --- a/src/platform/Darwin/DnssdContexts.cpp +++ b/src/platform/Darwin/DnssdContexts.cpp @@ -384,7 +384,7 @@ void ResolveContext::DispatchSuccess() continue; } - ChipLogDetail(Discovery, "Mdns: Resolve success on interface %" PRIu32, interface.first); + ChipLogProgress(Discovery, "Mdns: Resolve success on interface %" PRIu32, interface.first); callback(context, &interface.second.service, Span(ips.data(), ips.size()), CHIP_NO_ERROR); break; } @@ -412,11 +412,11 @@ CHIP_ERROR ResolveContext::OnNewAddress(uint32_t interfaceId, const struct socka ReturnErrorOnFailure(chip::Inet::IPAddress::GetIPAddressFromSockAddr(*address, ip)); interfaces[interfaceId].addresses.push_back(ip); -#ifdef CHIP_DETAIL_LOGGING +#ifdef CHIP_PROGRESS_LOGGING char addrStr[INET6_ADDRSTRLEN]; ip.ToString(addrStr, sizeof(addrStr)); - ChipLogDetail(Discovery, "Mdns: %s interface: %" PRIu32 " ip:%s", __func__, interfaceId, addrStr); -#endif // CHIP_DETAIL_LOGGING + ChipLogProgress(Discovery, "Mdns: %s interface: %" PRIu32 " ip:%s", __func__, interfaceId, addrStr); +#endif // CHIP_PROGRESS_LOGGING return CHIP_NO_ERROR; } @@ -449,7 +449,7 @@ bool ResolveContext::HasAddress() void ResolveContext::OnNewInterface(uint32_t interfaceId, const char * fullname, const char * hostnameWithDomain, uint16_t port, uint16_t txtLen, const unsigned char * txtRecord) { -#if CHIP_DETAIL_LOGGING +#if CHIP_PROGRESS_LOGGING std::string txtString; auto txtRecordIter = txtRecord; size_t remainingLen = txtLen; @@ -480,9 +480,9 @@ void ResolveContext::OnNewInterface(uint32_t interfaceId, const char * fullname, txtRecordIter += len; remainingLen -= len; } -#endif // CHIP_DETAIL_LOGGING - ChipLogDetail(Discovery, "Mdns : %s hostname:%s fullname:%s interface: %" PRIu32 " port: %u TXT:\"%s\"", __func__, - hostnameWithDomain, fullname, interfaceId, ntohs(port), txtString.c_str()); +#endif // CHIP_PROGRESS_LOGGING + ChipLogProgress(Discovery, "Mdns : %s hostname:%s fullname:%s interface: %" PRIu32 " port: %u TXT:\"%s\"", __func__, + hostnameWithDomain, fullname, interfaceId, ntohs(port), txtString.c_str()); InterfaceInfo interface; interface.service.mPort = ntohs(port); diff --git a/src/platform/Darwin/DnssdHostNameRegistrar.cpp b/src/platform/Darwin/DnssdHostNameRegistrar.cpp index a2415791d4aa4a..fd360f66237c74 100644 --- a/src/platform/Darwin/DnssdHostNameRegistrar.cpp +++ b/src/platform/Darwin/DnssdHostNameRegistrar.cpp @@ -36,7 +36,7 @@ namespace Dnssd { namespace { -#if CHIP_DETAIL_LOGGING +#if CHIP_PROGRESS_LOGGING constexpr const char * kPathStatusInvalid = "Invalid"; constexpr const char * kPathStatusUnsatisfied = "Unsatisfied"; constexpr const char * kPathStatusSatisfied = "Satisfied"; @@ -118,7 +118,7 @@ void LogDetails(uint32_t interfaceId, InetInterfacesVector inetInterfaces, Inet6 { char addr[INET_ADDRSTRLEN] = {}; inet_ntop(AF_INET, &inetInterface.second, addr, sizeof(addr)); - ChipLogDetail(Discovery, "\t\t* ipv4: %s", addr); + ChipLogProgress(Discovery, "\t\t* ipv4: %s", addr); } } @@ -128,7 +128,7 @@ void LogDetails(uint32_t interfaceId, InetInterfacesVector inetInterfaces, Inet6 { char addr[INET6_ADDRSTRLEN] = {}; inet_ntop(AF_INET6, &inet6Interface.second, addr, sizeof(addr)); - ChipLogDetail(Discovery, "\t\t* ipv6: %s", addr); + ChipLogProgress(Discovery, "\t\t* ipv6: %s", addr); } } } @@ -136,7 +136,7 @@ void LogDetails(uint32_t interfaceId, InetInterfacesVector inetInterfaces, Inet6 void LogDetails(nw_path_t path) { auto status = nw_path_get_status(path); - ChipLogDetail(Discovery, "Status: %s", GetPathStatusString(status)); + ChipLogProgress(Discovery, "Status: %s", GetPathStatusString(status)); } void LogDetails(InetInterfacesVector inetInterfaces, Inet6InterfacesVector inet6Interfaces) @@ -156,7 +156,7 @@ void LogDetails(InetInterfacesVector inetInterfaces, Inet6InterfacesVector inet6 { char interfaceName[IFNAMSIZ] = {}; if_indextoname(interfaceId, interfaceName); - ChipLogDetail(Discovery, "\t%s (%u)", interfaceName, interfaceId); + ChipLogProgress(Discovery, "\t%s (%u)", interfaceName, interfaceId); LogDetails(interfaceId, inetInterfaces, inet6Interfaces); } } @@ -166,10 +166,10 @@ void LogDetails(nw_interface_t interface, InetInterfacesVector inetInterfaces, I auto interfaceId = nw_interface_get_index(interface); auto interfaceName = nw_interface_get_name(interface); auto interfaceType = nw_interface_get_type(interface); - ChipLogDetail(Discovery, "\t%s (%u / %s)", interfaceName, interfaceId, GetInterfaceTypeString(interfaceType)); + ChipLogProgress(Discovery, "\t%s (%u / %s)", interfaceName, interfaceId, GetInterfaceTypeString(interfaceType)); LogDetails(interfaceId, inetInterfaces, inet6Interfaces); } -#endif // CHIP_DETAIL_LOGGING +#endif // CHIP_PROGRESS_LOGGING bool HasValidFlags(unsigned int flags, bool allowLoopbackOnly) { @@ -205,7 +205,7 @@ void ShouldUseVersion(chip::Inet::IPAddressType addressType, bool & shouldUseIPv static void OnRegisterRecord(DNSServiceRef sdRef, DNSRecordRef recordRef, DNSServiceFlags flags, DNSServiceErrorType err, void * context) { - ChipLogDetail(Discovery, "Mdns: %s flags: %d", __func__, flags); + ChipLogProgress(Discovery, "Mdns: %s flags: %d", __func__, flags); if (kDNSServiceErr_NoError != err) { ChipLogError(Discovery, "%s (%s)", __func__, Error::ToString(err)); @@ -304,9 +304,9 @@ CHIP_ERROR HostNameRegistrar::StartMonitorInterfaces(OnInterfaceChanges interfac nw_path_monitor_set_queue(mInterfaceMonitor, chip::DeviceLayer::PlatformMgrImpl().GetWorkQueue()); nw_path_monitor_set_update_handler(mInterfaceMonitor, ^(nw_path_t path) { -#if CHIP_DETAIL_LOGGING +#if CHIP_PROGRESS_LOGGING LogDetails(path); -#endif // CHIP_DETAIL_LOGGING +#endif // CHIP_PROGRESS_LOGGING __block InetInterfacesVector inet; __block Inet6InterfacesVector inet6; @@ -315,9 +315,9 @@ CHIP_ERROR HostNameRegistrar::StartMonitorInterfaces(OnInterfaceChanges interfac // loopback interface with the specified interface id. If the specified interface id is kDNSServiceInterfaceIndexAny, it // will look for all available loopback interfaces. GetInterfaceAddresses(mInterfaceId, mAddressType, inet, inet6, true /* searchLoopbackOnly */); -#if CHIP_DETAIL_LOGGING +#if CHIP_PROGRESS_LOGGING LogDetails(inet, inet6); -#endif // CHIP_DETAIL_LOGGING +#endif // CHIP_PROGRESS_LOGGING auto status = nw_path_get_status(path); if (status == nw_path_status_satisfied) @@ -328,9 +328,9 @@ CHIP_ERROR HostNameRegistrar::StartMonitorInterfaces(OnInterfaceChanges interfac auto targetInterfaceId = nw_interface_get_index(interface); GetInterfaceAddresses(targetInterfaceId, mAddressType, inet, inet6); -#if CHIP_DETAIL_LOGGING +#if CHIP_PROGRESS_LOGGING LogDetails(interface, inet, inet6); -#endif // CHIP_DETAIL_LOGGING +#endif // CHIP_PROGRESS_LOGGING return true; }); } diff --git a/src/platform/Darwin/DnssdImpl.cpp b/src/platform/Darwin/DnssdImpl.cpp index 54ed9c8dd4bea0..584b9b553d655c 100644 --- a/src/platform/Darwin/DnssdImpl.cpp +++ b/src/platform/Darwin/DnssdImpl.cpp @@ -171,8 +171,8 @@ namespace { static void OnRegister(DNSServiceRef sdRef, DNSServiceFlags flags, DNSServiceErrorType err, const char * name, const char * type, const char * domain, void * context) { - ChipLogDetail(Discovery, "Mdns: %s name: %s, type: %s, domain: %s, flags: %d", __func__, StringOrNullMarker(name), - StringOrNullMarker(type), StringOrNullMarker(domain), flags); + ChipLogProgress(Discovery, "Mdns: %s name: %s, type: %s, domain: %s, flags: %d", __func__, StringOrNullMarker(name), + StringOrNullMarker(type), StringOrNullMarker(domain), flags); auto sdCtx = reinterpret_cast(context); sdCtx->Finalize(err); @@ -181,8 +181,8 @@ static void OnRegister(DNSServiceRef sdRef, DNSServiceFlags flags, DNSServiceErr CHIP_ERROR Register(void * context, DnssdPublishCallback callback, uint32_t interfaceId, const char * type, const char * name, uint16_t port, ScopedTXTRecord & record, Inet::IPAddressType addressType, const char * hostname) { - ChipLogDetail(Discovery, "Registering service %s on host %s with port %u and type: %s on interface id: %" PRIu32, - StringOrNullMarker(name), StringOrNullMarker(hostname), port, StringOrNullMarker(type), interfaceId); + ChipLogProgress(Discovery, "Registering service %s on host %s with port %u and type: %s on interface id: %" PRIu32, + StringOrNullMarker(name), StringOrNullMarker(hostname), port, StringOrNullMarker(type), interfaceId); RegisterContext * sdCtx = nullptr; if (CHIP_NO_ERROR == MdnsContexts::GetInstance().GetRegisterContextOfType(type, &sdCtx)) @@ -207,8 +207,8 @@ CHIP_ERROR Register(void * context, DnssdPublishCallback callback, uint32_t inte void OnBrowseAdd(BrowseContext * context, const char * name, const char * type, const char * domain, uint32_t interfaceId) { - ChipLogDetail(Discovery, "Mdns: %s name: %s, type: %s, domain: %s, interface: %" PRIu32, __func__, StringOrNullMarker(name), - StringOrNullMarker(type), StringOrNullMarker(domain), interfaceId); + ChipLogProgress(Discovery, "Mdns: %s name: %s, type: %s, domain: %s, interface: %" PRIu32, __func__, StringOrNullMarker(name), + StringOrNullMarker(type), StringOrNullMarker(domain), interfaceId); VerifyOrReturn(strcmp(kLocalDot, domain) == 0); @@ -234,8 +234,8 @@ void OnBrowseAdd(BrowseContext * context, const char * name, const char * type, void OnBrowseRemove(BrowseContext * context, const char * name, const char * type, const char * domain, uint32_t interfaceId) { - ChipLogDetail(Discovery, "Mdns: %s name: %s, type: %s, domain: %s, interface: %" PRIu32, __func__, StringOrNullMarker(name), - StringOrNullMarker(type), StringOrNullMarker(domain), interfaceId); + ChipLogProgress(Discovery, "Mdns: %s name: %s, type: %s, domain: %s, interface: %" PRIu32, __func__, StringOrNullMarker(name), + StringOrNullMarker(type), StringOrNullMarker(domain), interfaceId); VerifyOrReturn(name != nullptr); VerifyOrReturn(strcmp(kLocalDot, domain) == 0); @@ -282,6 +282,8 @@ CHIP_ERROR Browse(void * context, DnssdBrowseCallback callback, uint32_t interfa static void OnGetAddrInfo(DNSServiceRef sdRef, DNSServiceFlags flags, uint32_t interfaceId, DNSServiceErrorType err, const char * hostname, const struct sockaddr * address, uint32_t ttl, void * context) { + ChipLogProgress(Discovery, "Mdns: %s flags: %d, interface: %u, hostname: %s", __func__, flags, (unsigned) interfaceId, + StringOrNullMarker(hostname)); auto sdCtx = reinterpret_cast(context); ReturnOnFailure(MdnsContexts::GetInstance().Has(sdCtx)); LogOnFailure(__func__, err); @@ -316,6 +318,8 @@ static void OnResolve(DNSServiceRef sdRef, DNSServiceFlags flags, uint32_t inter const char * fullname, const char * hostname, uint16_t port, uint16_t txtLen, const unsigned char * txtRecord, void * context) { + ChipLogProgress(Discovery, "Mdns: %s flags: %d, interface: %u, fullname: %s, hostname: %s, port: %u", __func__, flags, + (unsigned) interfaceId, StringOrNullMarker(fullname), StringOrNullMarker(hostname), port); auto sdCtx = reinterpret_cast(context); ReturnOnFailure(MdnsContexts::GetInstance().Has(sdCtx)); LogOnFailure(__func__, err); @@ -341,8 +345,8 @@ static void OnResolve(DNSServiceRef sdRef, DNSServiceFlags flags, uint32_t inter static CHIP_ERROR Resolve(void * context, DnssdResolveCallback callback, uint32_t interfaceId, chip::Inet::IPAddressType addressType, const char * type, const char * name) { - ChipLogDetail(Discovery, "Resolve type=%s name=%s interface=%" PRIu32, StringOrNullMarker(type), StringOrNullMarker(name), - interfaceId); + ChipLogProgress(Discovery, "Resolve type=%s name=%s interface=%" PRIu32, StringOrNullMarker(type), StringOrNullMarker(name), + interfaceId); // This is a little silly, in that resolves for the same name, type, etc get // coalesced by the underlying mDNSResponder anyway. But we need to keep @@ -489,6 +493,7 @@ CHIP_ERROR ChipDnssdResolve(DnssdService * service, chip::Inet::InterfaceId inte void ChipDnssdResolveNoLongerNeeded(const char * instanceName) { + ChipLogProgress(Discovery, "No longer need resolve for %s", instanceName); auto existingCtx = MdnsContexts::GetInstance().GetExistingResolveForInstanceName(instanceName); VerifyOrReturn(existingCtx != nullptr); VerifyOrReturn(*existingCtx->consumerCounter != 0);