Bug 1953459 - Add profiler markers along the native HTTPS RR resolution path

dom/html/HTMLDNSPrefetch.cpp

@@ -239,14 +239,8 @@ nsresult HTMLDNSPrefetch::Prefetch(
     return NS_ERROR_NOT_AVAILABLE;
 
   nsCOMPtr<nsICancelable> tmpOutstanding;
-  nsresult rv = sDNSService->AsyncResolveNative(
-      NS_ConvertUTF16toUTF8(hostname), nsIDNSService::RESOLVE_TYPE_DEFAULT,
-      flags | nsIDNSService::RESOLVE_SPECULATE, nullptr, sDNSListener, nullptr,
-      aPartitionedPrincipalOriginAttributes, getter_AddRefs(tmpOutstanding));
-  if (NS_FAILED(rv)) {
-    return rv;
-  }
-
+  // Issue the HTTPS RR query before the address query so the slower lookup
+  // does not queue behind the address lookup.
   if (StaticPrefs::network_dns_upgrade_with_https_rr() ||
       StaticPrefs::network_dns_use_https_rr_as_altsvc()) {
     (void)sDNSService->AsyncResolveNative(
@@ -256,7 +250,10 @@ nsresult HTMLDNSPrefetch::Prefetch(
         getter_AddRefs(tmpOutstanding));
   }
 
-  return NS_OK;
+  return sDNSService->AsyncResolveNative(
+      NS_ConvertUTF16toUTF8(hostname), nsIDNSService::RESOLVE_TYPE_DEFAULT,
+      flags | nsIDNSService::RESOLVE_SPECULATE, nullptr, sDNSListener, nullptr,
+      aPartitionedPrincipalOriginAttributes, getter_AddRefs(tmpOutstanding));
 }
 
 nsresult HTMLDNSPrefetch::Prefetch(
@@ -399,22 +396,23 @@ void HTMLDNSPrefetch::SendRequest(Element& aElement,
   } else {
     nsCOMPtr<nsICancelable> tmpOutstanding;
 
-    rv = sDNSService->AsyncResolveNative(
-        hostName, nsIDNSService::RESOLVE_TYPE_DEFAULT,
-        aFlags | nsIDNSService::RESOLVE_SPECULATE, nullptr, sDNSListener,
-        nullptr, oa, getter_AddRefs(tmpOutstanding));
-    if (NS_FAILED(rv)) {
-      return;
-    }
-
-    // Fetch HTTPS RR if needed.
+    // Fetch HTTPS RR if needed, before the address query so the slower
+    // lookup does not queue behind the address lookup.
     if (StaticPrefs::network_dns_upgrade_with_https_rr() ||
         StaticPrefs::network_dns_use_https_rr_as_altsvc()) {
       sDNSService->AsyncResolveNative(
           hostName, nsIDNSService::RESOLVE_TYPE_HTTPSSVC,
           aFlags | nsIDNSService::RESOLVE_SPECULATE, nullptr, sDNSListener,
           nullptr, oa, getter_AddRefs(tmpOutstanding));
     }
+
+    rv = sDNSService->AsyncResolveNative(
+        hostName, nsIDNSService::RESOLVE_TYPE_DEFAULT,
+        aFlags | nsIDNSService::RESOLVE_SPECULATE, nullptr, sDNSListener,
+        nullptr, oa, getter_AddRefs(tmpOutstanding));
+    if (NS_FAILED(rv)) {
+      return;
+    }
   }
 
   // Tell element that deferred prefetch was requested.

netwerk/base/nsDNSPrefetch.cpp

@@ -3,10 +3,14 @@
  * file, You can obtain one at http://mozilla.org/MPL/2.0/. */
 
 #include "nsDNSPrefetch.h"
+#include "DNSProfilerMarkers.h"
 #include "nsCOMPtr.h"
+#include "nsPrintfCString.h"
 #include "nsString.h"
 #include "nsThreadUtils.h"
 
+#include <inttypes.h>
+
 #include "nsIDNSAdditionalInfo.h"
 #include "nsIDNSListener.h"
 #include "nsIDNSService.h"
@@ -67,10 +71,19 @@ nsresult nsDNSPrefetch::Prefetch(nsIDNSService::DNSFlags flags) {
 
   flags |= nsIDNSService::GetFlagsFromTRRMode(mTRRMode);
 
-  return sDNSService->AsyncResolveNative(
+  nsresult rv = sDNSService->AsyncResolveNative(
       mHostname, nsIDNSService::RESOLVE_TYPE_DEFAULT,
       flags | nsIDNSService::RESOLVE_SPECULATE, nullptr, this, target,
       mOriginAttributes, getter_AddRefs(tmpOutstanding));
+  if (profiler_thread_is_being_profiled_for_markers()) {
+    PROFILER_MARKER("DNS prefetch", NETWORK, {}, DNSQueryMarker, mHostname,
+                    "A+AAAA", NS_SUCCEEDED(rv) ? "requested"_ns : "failed"_ns,
+                    NS_FAILED(rv) ? nsPrintfCString("0x%08" PRIx32,
+                                                    static_cast<uint32_t>(rv))
+                                  : nsPrintfCString(""),
+                    int64_t(-1), ""_ns);
+  }
+  return rv;
 }
 
 nsresult nsDNSPrefetch::PrefetchLow(nsIDNSService::DNSFlags aFlags) {
@@ -140,9 +153,19 @@ nsresult nsDNSPrefetch::FetchHTTPSSVC(
   if (mPort != -1) {
     sDNSService->NewAdditionalInfo(""_ns, mPort, getter_AddRefs(info));
   }
-  return sDNSService->AsyncResolveNative(
+  nsresult rv = sDNSService->AsyncResolveNative(
       mHostname, nsIDNSService::RESOLVE_TYPE_HTTPSSVC, flags, info, listener,
       target, mOriginAttributes, getter_AddRefs(tmpOutstanding));
+  if (profiler_thread_is_being_profiled_for_markers()) {
+    PROFILER_MARKER(
+        "DNS HTTPSSVC fetch", NETWORK, {}, DNSQueryMarker, mHostname, "HTTPS",
+        NS_SUCCEEDED(rv) ? "requested"_ns : "failed"_ns,
+        NS_FAILED(rv)
+            ? nsPrintfCString("0x%08" PRIx32, static_cast<uint32_t>(rv))
+            : nsPrintfCString(""),
+        int64_t(-1), aPrefetch ? "speculative"_ns : ""_ns);
+  }
+  return rv;
 }
 
 NS_IMPL_ISUPPORTS(nsDNSPrefetch, nsIDNSListener)

netwerk/dns/ChildDNSService.cpp

@@ -3,6 +3,7 @@
  * file, You can obtain one at http://mozilla.org/MPL/2.0/. */
 
 #include "mozilla/net/ChildDNSService.h"
+#include "DNSProfilerMarkers.h"
 #include "nsDNSPrefetch.h"
 #include "nsIDNSListener.h"
 #include "nsIOService.h"
@@ -112,6 +113,12 @@ nsresult ChildDNSService::AsyncResolveInternal(
   }
 
   if (mDisablePrefetch && (flags & RESOLVE_SPECULATE)) {
+    if (profiler_thread_is_being_profiled_for_markers()) {
+      PROFILER_MARKER("DNS prefetch blocked", NETWORK, {}, DNSQueryMarker,
+                      hostname, DNSQueryTypeString(type, 0),
+                      "dropped: network.dns.disablePrefetch"_ns, ""_ns,
+                      int64_t(-1), ""_ns);
+    }
     return NS_ERROR_DNS_LOOKUP_QUEUE_FULL;
   }
 

netwerk/dns/DNSListenerProxy.cpp

@@ -3,10 +3,15 @@
  * file, You can obtain one at http://mozilla.org/MPL/2.0/. */
 
 #include "mozilla/net/DNSListenerProxy.h"
+#include "mozilla/ProfilerMarkers.h"
 #include "mozilla/StaticPrefs_network.h"
+#include "mozilla/TimeStamp.h"
 #include "nsICancelable.h"
+#include "nsPrintfCString.h"
 #include "nsThreadUtils.h"
 
+#include <inttypes.h>
+
 namespace mozilla {
 namespace net {
 
@@ -24,8 +29,14 @@ DNSListenerProxy::OnLookupComplete(nsICancelable* aRequest,
   nsCOMPtr<nsICancelable> request = aRequest;
   nsCOMPtr<nsIDNSRecord> record = aRecord;
 
+  TimeStamp dispatchTime = TimeStamp::Now();
   nsCOMPtr<nsIRunnable> event = NS_NewRunnableFunction(
-      "DNSListenerProxy::OnLookupComplete", [self, request, record, aStatus]() {
+      "DNSListenerProxy::OnLookupComplete",
+      [self, request, record, aStatus, dispatchTime]() {
+        PROFILER_MARKER_TEXT("DNS OnLookupComplete dispatch", NETWORK,
+                             MarkerTiming::IntervalUntilNowFrom(dispatchTime),
+                             nsPrintfCString("status=0x%08" PRIx32,
+                                             static_cast<uint32_t>(aStatus)));
         (void)self->mListener->OnLookupComplete(request, record, aStatus);
         self->mListener = nullptr;
       });

netwerk/dns/DNSProfilerMarkers.h

@@ -0,0 +1,90 @@
+/* This Source Code Form is subject to the terms of the Mozilla Public
+ * License, v. 2.0. If a copy of the MPL was not distributed with this
+ * file, You can obtain one at http://mozilla.org/MPL/2.0/. */
+
+#ifndef DNSProfilerMarkers_h__
+#define DNSProfilerMarkers_h__
+
+#include "mozilla/ProfilerMarkers.h"
+#include "mozilla/Span.h"
+#include "nsIDNSService.h"
+#include "prio.h"
+
+namespace geckoprofiler::markers {
+
+// Profiler marker used along the DNS resolution code path, with a focus on
+// making HTTPS RR (HTTPSSVC) resolution debuggable. Together with the
+// "Happy Eyeballs" markers emitted by
+// netwerk/protocol/http/happy_eyeballs_glue, these markers break down where
+// time is spent between a consumer requesting a DNS record and the response
+// being delivered back to it.
+struct DNSQueryMarker {
+  static constexpr mozilla::Span<const char> MarkerTypeName() {
+    return mozilla::MakeStringSpan("DNSQuery");
+  }
+  static void StreamJSONMarkerData(
+      mozilla::baseprofiler::SpliceableJSONWriter& aWriter,
+      const mozilla::ProfilerString8View& aHost,
+      const mozilla::ProfilerString8View& aQueryType,
+      const mozilla::ProfilerString8View& aOutcome,
+      const mozilla::ProfilerString8View& aStatus, int64_t aRecords,
+      const mozilla::ProfilerString8View& aDetail) {
+    aWriter.StringProperty("host", aHost);
+    aWriter.UniqueStringProperty("qtype", aQueryType);
+    if (aOutcome.Length() != 0) {
+      aWriter.UniqueStringProperty("outcome", aOutcome);
+    }
+    if (aStatus.Length() != 0) {
+      aWriter.StringProperty("status", aStatus);
+    }
+    if (aRecords >= 0) {
+      aWriter.IntProperty("records", aRecords);
+    }
+    if (aDetail.Length() != 0) {
+      aWriter.StringProperty("detail", aDetail);
+    }
+  }
+  static mozilla::MarkerSchema MarkerTypeDisplay() {
+    using MS = mozilla::MarkerSchema;
+    MS schema(MS::Location::MarkerChart, MS::Location::MarkerTable);
+    schema.SetChartLabel("{marker.data.qtype} {marker.data.host}");
+    schema.SetTableLabel(
+        "{marker.name} - {marker.data.qtype} {marker.data.host} "
+        "{marker.data.outcome} {marker.data.detail}");
+    schema.AddKeyLabelFormat("host", "Host", MS::Format::SanitizedString);
+    schema.AddKeyLabelFormat("qtype", "Record Type", MS::Format::UniqueString);
+    schema.AddKeyLabelFormat("outcome", "Outcome", MS::Format::UniqueString);
+    schema.AddKeyLabelFormat("status", "Status", MS::Format::String);
+    schema.AddKeyLabelFormat("records", "Records", MS::Format::Integer);
+    schema.AddKeyLabelFormat("detail", "Detail", MS::Format::SanitizedString);
+    return schema;
+  }
+};
+
+}  // namespace geckoprofiler::markers
+
+namespace mozilla::net {
+
+// Human readable record type for a (RESOLVE_TYPE_*, address family) pair.
+inline mozilla::ProfilerString8View DNSQueryTypeString(uint16_t aType,
+                                                       uint16_t aAF) {
+  switch (aType) {
+    case nsIDNSService::RESOLVE_TYPE_HTTPSSVC:
+      return "HTTPS";
+    case nsIDNSService::RESOLVE_TYPE_TXT:
+      return "TXT";
+    default:
+      break;
+  }
+  if (aAF == PR_AF_INET) {
+    return "A";
+  }
+  if (aAF == PR_AF_INET6) {
+    return "AAAA";
+  }
+  return "A+AAAA";
+}
+
+}  // namespace mozilla::net
+
+#endif  // DNSProfilerMarkers_h__

netwerk/dns/PlatformDNSAndroid.cpp

@@ -2,14 +2,18 @@
  * License, v. 2.0. If a copy of the MPL was not distributed with this
  * file, You can obtain one at http://mozilla.org/MPL/2.0/. */
 
+#include "DNSProfilerMarkers.h"
 #include "GetAddrInfo.h"
 #include "mozilla/glean/NetwerkMetrics.h"
 #include "mozilla/net/DNSPacket.h"
 #include "nsIDNSService.h"
+#include "nsPrintfCString.h"
 #include "mozilla/Maybe.h"
 #include "mozilla/Atomics.h"
 #include "mozilla/StaticPrefs_network.h"
 
+#include <inttypes.h>
+
 #include <netinet/in.h>
 #include <resolv.h>
 #include <poll.h>
@@ -110,6 +114,13 @@ nsresult ResolveHTTPSRecordImpl(const nsACString& aHost,
       });
   mozilla::glean::networking::dns_native_https_call_time.AccumulateRawDuration(
       TimeStamp::Now() - startTime);
+  if (profiler_thread_is_being_profiled_for_markers()) {
+    PROFILER_MARKER("DNS OS query", NETWORK,
+                    MarkerTiming::IntervalUntilNowFrom(startTime),
+                    DNSQueryMarker, host, "HTTPS", ""_ns,
+                    nsPrintfCString("0x%08" PRIx32, static_cast<uint32_t>(rv)),
+                    int64_t(-1), "android_res_nquery"_ns);
+  }
   if (NS_FAILED(rv)) {
     LOG("failed rv");
     return rv;

netwerk/dns/PlatformDNSMac.cpp

@@ -2,12 +2,16 @@
  * License, v. 2.0. If a copy of the MPL was not distributed with this
  * file, You can obtain one at http://mozilla.org/MPL/2.0/. */
 
+#include "DNSProfilerMarkers.h"
 #include "GetAddrInfo.h"
 #include "mozilla/glean/NetwerkMetrics.h"
 #include "mozilla/net/DNSPacket.h"
 #include "nsIDNSService.h"
+#include "nsPrintfCString.h"
 #include "mozilla/StaticPrefs_network.h"
 
+#include <inttypes.h>
+
 #include <dns_sd.h>
 #include <poll.h>
 #include <arpa/inet.h>
@@ -157,6 +161,14 @@ nsresult ResolveHTTPSRecordImpl(const nsACString& aHost,
   mozilla::glean::networking::dns_native_https_call_time.AccumulateRawDuration(
       TimeStamp::Now() - startTime);
 
+  if (profiler_thread_is_being_profiled_for_markers()) {
+    PROFILER_MARKER(
+        "DNS OS query", NETWORK, MarkerTiming::IntervalUntilNowFrom(startTime),
+        DNSQueryMarker, host, "HTTPS", ""_ns,
+        nsPrintfCString("0x%08" PRIx32, static_cast<uint32_t>(context.mRv)),
+        int64_t(-1), nsPrintfCString("DNSServiceQueryRecord poll=%d", result));
+  }
+
   LOG("resolving %s done %x ttl=%u", host.get(), context.mRv, aTTL);
   if (NS_FAILED(context.mRv)) {
     return context.mRv;

netwerk/dns/PlatformDNSUnix.cpp

@@ -2,10 +2,12 @@
  * License, v. 2.0. If a copy of the MPL was not distributed with this
  * file, You can obtain one at http://mozilla.org/MPL/2.0/. */
 
+#include "DNSProfilerMarkers.h"
 #include "GetAddrInfo.h"
 #include "mozilla/glean/NetwerkMetrics.h"
 #include "mozilla/net/DNSPacket.h"
 #include "nsIDNSService.h"
+#include "nsPrintfCString.h"
 #include "mozilla/Mutex.h"
 #include "mozilla/StaticPrefs_network.h"
 #include "mozilla/ThreadLocal.h"
@@ -71,6 +73,13 @@ nsresult ResolveHTTPSRecordImpl(const nsACString& aHost,
 
         mozilla::glean::networking::dns_native_https_call_time
             .AccumulateRawDuration(TimeStamp::Now() - startTime);
+        if (profiler_thread_is_being_profiled_for_markers()) {
+          PROFILER_MARKER("DNS OS query", NETWORK,
+                          MarkerTiming::IntervalUntilNowFrom(startTime),
+                          DNSQueryMarker, host, "HTTPS", ""_ns, ""_ns,
+                          int64_t(-1),
+                          nsPrintfCString("res_nquery len=%d", len));
+        }
         if (len < 0) {
           LOG("DNS query failed");
         }

netwerk/dns/PlatformDNSWin.cpp

@@ -2,10 +2,12 @@
  * License, v. 2.0. If a copy of the MPL was not distributed with this
  * file, You can obtain one at http://mozilla.org/MPL/2.0/. */
 
+#include "DNSProfilerMarkers.h"
 #include "GetAddrInfo.h"
 #include "mozilla/glean/NetwerkMetrics.h"
 #include "mozilla/net/DNSPacket.h"
 #include "nsIDNSService.h"
+#include "nsPrintfCString.h"
 #include "mozilla/Maybe.h"
 #include "mozilla/ScopeExit.h"
 #include "mozilla/StaticPrefs_network.h"
@@ -48,6 +50,13 @@ nsresult ResolveHTTPSRecordImpl(const nsACString& aHost,
   mozilla::glean::networking::dns_native_https_call_time.AccumulateRawDuration(
       TimeStamp::Now() - startTime);
 
+  if (profiler_thread_is_being_profiled_for_markers()) {
+    PROFILER_MARKER("DNS OS query", NETWORK,
+                    MarkerTiming::IntervalUntilNowFrom(startTime),
+                    DNSQueryMarker, host, "HTTPS", ""_ns, ""_ns, int64_t(-1),
+                    nsPrintfCString("DnsQuery_A status=%ld", status));
+  }
+
   if (status != ERROR_SUCCESS) {
     LOG("DnsQuery_A failed with error: %ld\n", status);
     return NS_ERROR_UNKNOWN_HOST;