fix(dnsping): make output more actionable

internal/experiment/dnsping/dnsping.go

@@ -20,7 +20,7 @@ import (
 
 const (
 	testName    = "dnsping"
-	testVersion = "0.3.0"
+	testVersion = "0.4.0"
 )
 
 // Config contains the experiment configuration.
@@ -87,12 +87,15 @@ var (
 
 // Run implements ExperimentMeasurer.Run.
 func (m *Measurer) Run(ctx context.Context, args *model.ExperimentArgs) error {
+	// unpack experiment args
 	_ = args.Callbacks
 	measurement := args.Measurement
 	sess := args.Session
 	if measurement.Input == "" {
 		return errNoInputProvided
 	}
+
+	// parse experiment input
 	parsed, err := url.Parse(string(measurement.Input))
 	if err != nil {
 		return fmt.Errorf("%w: %s", errInputIsNotAnURL, err.Error())
@@ -103,50 +106,83 @@ func (m *Measurer) Run(ctx context.Context, args *model.ExperimentArgs) error {
 	if parsed.Port() == "" {
 		return errMissingPort
 	}
+
+	// create the empty measurement test keys
 	tk := NewTestKeys()
 	measurement.TestKeys = tk
+
+	// parse the domains to measure
 	domains := strings.Split(m.config.domains(), " ")
+
+	// spawn a pinger for each domain to measure
 	wg := new(sync.WaitGroup)
 	wg.Add(len(domains))
 	for _, domain := range domains {
 		go m.dnsPingLoop(ctx, measurement.MeasurementStartTimeSaved, sess.Logger(), parsed.Host, domain, wg, tk)
 	}
+
+	// block until all pingers are done
 	wg.Wait()
+
+	// generate textual summary
+	summarize(tk)
+
 	return nil // return nil so we always submit the measurement
 }
 
 // dnsPingLoop sends all the ping requests and emits the results onto the out channel.
 func (m *Measurer) dnsPingLoop(ctx context.Context, zeroTime time.Time, logger model.Logger,
 	address string, domain string, wg *sync.WaitGroup, tk *TestKeys) {
+	// make sure the parent knows when we're done
 	defer wg.Done()
+
+	// create ticker so we know when to send the next DNS ping
 	ticker := time.NewTicker(m.config.delay())
 	defer ticker.Stop()
+
+	// start a goroutine for each ping repetition
 	for i := int64(0); i < m.config.repetitions(); i++ {
 		wg.Add(1)
 		go m.dnsRoundTrip(ctx, i, zeroTime, logger, address, domain, wg, tk)
+
+		// make sure we wait until it's time to send the next ping
 		<-ticker.C
 	}
 }
 
 // dnsRoundTrip performs a round trip and returns the results to the caller.
 func (m *Measurer) dnsRoundTrip(ctx context.Context, index int64, zeroTime time.Time,
 	logger model.Logger, address string, domain string, wg *sync.WaitGroup, tk *TestKeys) {
+	// create context bound to timeout
 	// TODO(bassosimone): make the timeout user-configurable
 	ctx, cancel := context.WithTimeout(ctx, 3*time.Second)
 	defer cancel()
+
+	// make sure we inform the parent when we're done
 	defer wg.Done()
-	pings := []*SinglePing{}
+
+	// create trace for collecting information
 	trace := measurexlite.NewTrace(index, zeroTime)
-	ol := logx.NewOperationLogger(logger, "DNSPing #%d %s %s", index, address, domain)
+
+	// create dialer and resolver
+	//
 	// TODO(bassosimone, DecFox): what should we do if the user passes us a resolver with a
 	// domain name in terms of saving its results? Shall we save also the system resolver's lookups?
 	// Shall we, otherwise, pre-resolve the domain name to IP addresses once and for all? In such
 	// a case, shall we use all the available IP addresses or just some of them?
 	dialer := netxlite.NewDialerWithStdlibResolver(logger)
 	resolver := trace.NewParallelUDPResolver(logger, dialer, address)
-	_, err := resolver.LookupHost(ctx, domain)
-	ol.Stop(err)
-	delayedResp := trace.DelayedDNSResponseWithTimeout(ctx, 250*time.Millisecond)
+
+	// perform the lookup proper
+	ol := logx.NewOperationLogger(logger, "DNSPing #%d %s %s", index, address, domain)
+	addrs, err := resolver.LookupHost(ctx, domain)
+	stopOperationLogger(ol, addrs, err)
+
+	// wait a bit for delayed responses
+	delayedResps := trace.DelayedDNSResponseWithTimeout(ctx, 250*time.Millisecond)
+
+	// assemble the results by inspecting ordinary and late responses
+	pings := []*SinglePing{}
 	for _, lookup := range trace.DNSLookupsFromRoundTrip() {
 		// make sure we only include the query types we care about (in principle, there
 		// should be no other query, so we're doing this just for robustness).
@@ -155,18 +191,37 @@ func (m *Measurer) dnsRoundTrip(ctx context.Context, index int64, zeroTime time.
 				Query:            lookup,
 				DelayedResponses: []*model.ArchivalDNSLookupResult{},
 			}
-			// record the delayed responses of the corresponding query
-			for _, resp := range delayedResp {
-				if resp.QueryType == lookup.QueryType {
-					sp.DelayedResponses = append(sp.DelayedResponses, resp)
+
+			// now take care of delayed responses
+			if len(delayedResps) > 0 {
+				logger.Warnf("DNSPing #%d... received %d delayed responses", index, len(delayedResps))
+				// record the delayed responses of the corresponding query
+				for _, resp := range delayedResps {
+					if resp.QueryType == lookup.QueryType {
+						sp.DelayedResponses = append(sp.DelayedResponses, resp)
+					}
 				}
 			}
+
 			pings = append(pings, sp)
 		}
 	}
+
 	tk.addPings(pings)
 }
 
+type stoppableOperationLogger interface {
+	Stop(value any)
+}
+
+func stopOperationLogger(ol stoppableOperationLogger, addrs []string, err error) {
+	if err == nil {
+		ol.Stop(strings.Join(addrs, " "))
+	} else {
+		ol.Stop(err)
+	}
+}
+
 // NewExperimentMeasurer creates a new ExperimentMeasurer.
 func NewExperimentMeasurer(config Config) model.ExperimentMeasurer {
 	return &Measurer{config: config}

internal/experiment/dnsping/dnsping_test.go

@@ -3,10 +3,12 @@ package dnsping
 import (
 	"context"
 	"errors"
+	"strings"
 	"testing"
 	"time"
 
 	"github.com/google/go-cmp/cmp"
+	"github.com/google/go-cmp/cmp/cmpopts"
 	"github.com/ooni/netem"
 	"github.com/ooni/probe-cli/v3/internal/mocks"
 	"github.com/ooni/probe-cli/v3/internal/model"
@@ -49,7 +51,7 @@ func TestMeasurer_run(t *testing.T) {
 		if m.ExperimentName() != "dnsping" {
 			t.Fatal("invalid experiment name")
 		}
-		if m.ExperimentVersion() != "0.3.0" {
+		if m.ExperimentVersion() != "0.4.0" {
 			t.Fatal("invalid experiment version")
 		}
 		ctx := context.Background()
@@ -233,3 +235,32 @@ func TestMeasurer_run(t *testing.T) {
 		})
 	})
 }
+
+type mockableStoppableOperationLogger struct {
+	value any
+}
+
+func (ol *mockableStoppableOperationLogger) Stop(value any) {
+	ol.value = value
+}
+
+func TestStopOperationLogger(t *testing.T) {
+	t.Run("in case of success", func(t *testing.T) {
+		ol := &mockableStoppableOperationLogger{}
+		expect := []string{"8.8.8.8", "8.8.4.4"}
+		stopOperationLogger(ol, expect, nil)
+		if diff := cmp.Diff(strings.Join(expect, " "), ol.value); diff != "" {
+			t.Fatal(diff)
+		}
+	})
+
+	t.Run("in case of failure", func(t *testing.T) {
+		ol := &mockableStoppableOperationLogger{}
+		addrs := []string{"8.8.8.8", "8.8.4.4"} // the error should prevail
+		expect := errors.New("antani")
+		stopOperationLogger(ol, addrs, expect)
+		if diff := cmp.Diff(expect, ol.value, cmpopts.EquateErrors()); diff != "" {
+			t.Fatal(diff)
+		}
+	})
+}

internal/experiment/dnsping/summarize.go

@@ -0,0 +1,122 @@
+package dnsping
+
+import (
+	"fmt"
+	"io"
+	"os"
+
+	"github.com/ooni/probe-cli/v3/internal/geoipx"
+	"github.com/ooni/probe-cli/v3/internal/model"
+)
+
+// summarize summarizes the results.
+func summarize(tk *TestKeys) {
+	// print a summary of the addresses we have seen
+	as := &addressSummarizer{}
+	as.load(tk)
+	as.printf(os.Stdout)
+}
+
+// summarizeAddressStats contains stats about a resolved IP address
+// as generated by the [*addressSummarizer].
+type summarizeAddressStats struct {
+	Domain      string
+	IPAddress   string
+	ASN         uint
+	ASOrg       string
+	NumResolved int
+	Late        bool
+}
+
+// addressSummarizer creates a summary for addresses.
+//
+// The zero value is ready to use.
+type addressSummarizer struct {
+	m map[string]map[string]*summarizeAddressStats
+}
+
+func (as *addressSummarizer) printf(w io.Writer) {
+	fmt.Fprintf(w, "\n\n")
+
+	fmt.Fprintf(
+		w,
+		"%-30s %-48s %-10s %-30s %-10s %-10s\n",
+		"Domain",
+		"IPAddress",
+		"ASN",
+		"Org",
+		"#Seen",
+		"LateResponse",
+	)
+
+	fmt.Fprintf(w, "--------------------------------------------------------------------------------------------------------------------------------------------------\n")
+
+	for _, domainAddresses := range as.m {
+		for _, stats := range domainAddresses {
+			fmt.Fprintf(
+				w,
+				"%-30s %-48s %-10d %-30s %-10d %-10v\n",
+				stats.Domain,
+				stats.IPAddress,
+				stats.ASN,
+				stats.ASOrg,
+				stats.NumResolved,
+				stats.Late,
+			)
+		}
+	}
+
+	fmt.Fprintf(w, "\n\n")
+}
+
+// load loads information from the [*TestKeys].
+//
+// This method MAY MUTATE the [*addressSummarizer] content.
+func (as *addressSummarizer) load(tk *TestKeys) {
+	for _, ping := range tk.Pings {
+		as.loadQuery(ping.Query, false)
+		for _, q := range ping.DelayedResponses {
+			as.loadQuery(q, true)
+		}
+	}
+}
+
+// loadQuery loads a single query result.
+//
+// This method MAY MUTATE the [*addressSummarizer] content.
+func (as *addressSummarizer) loadQuery(query *model.ArchivalDNSLookupResult, late bool) {
+	for _, answer := range query.Answers {
+		switch answer.AnswerType {
+		case "A":
+			as.addAnswer(query.Hostname, answer.IPv4, late)
+
+		case "AAAA":
+			as.addAnswer(query.Hostname, answer.IPv6, late)
+		}
+	}
+}
+
+// addAnswer adds a single answer.
+//
+// This method MAY MUTATE the [*addressSummarizer] content.
+func (as *addressSummarizer) addAnswer(hostname string, ipAddr string, late bool) {
+	if as.m == nil {
+		as.m = make(map[string]map[string]*summarizeAddressStats)
+	}
+	if as.m[hostname] == nil {
+		as.m[hostname] = make(map[string]*summarizeAddressStats)
+	}
+	if as.m[hostname][ipAddr] == nil {
+		asNum, asOrg, _ := geoipx.LookupASN(ipAddr)
+		as.m[hostname][ipAddr] = &summarizeAddressStats{
+			Domain:      hostname,
+			IPAddress:   ipAddr,
+			NumResolved: 0,
+			Late:        late,
+			ASN:         asNum,
+			ASOrg:       asOrg,
+		}
+	}
+	entry := as.m[hostname][ipAddr]
+	entry.NumResolved++
+}

internal/experiment/dnsping/summarize_test.go

@@ -0,0 +1,56 @@
+package dnsping
+
+import (
+	"testing"
+
+	"github.com/google/go-cmp/cmp"
+	"github.com/ooni/probe-cli/v3/internal/model"
+)
+
+func TestAddressSummarizer(t *testing.T) {
+	t.Run("loadQuery", func(t *testing.T) {
+
+		// create a realistic query result with the correct addrs
+		result := &model.ArchivalDNSLookupResult{
+			Answers: []model.ArchivalDNSAnswer{{
+				AnswerType: "A",
+				IPv4:       "8.8.8.8",
+			}, {
+				AnswerType: "AAAA",
+				IPv6:       "2001:4860:4860::8844",
+			}},
+			Engine:    "getaddrinfo",
+			Hostname:  "dns.google",
+			QueryType: "ANY",
+		}
+
+		// ingest result
+		as := &addressSummarizer{}
+		as.loadQuery(result, false)
+
+		// define expectations
+		expect := map[string]map[string]*summarizeAddressStats{
+			"dns.google": {
+				"2001:4860:4860::8844": {
+					Domain:      "dns.google",
+					IPAddress:   "2001:4860:4860::8844",
+					ASN:         15169,
+					ASOrg:       "Google LLC",
+					NumResolved: 1,
+				},
+				"8.8.8.8": {
+					Domain:      "dns.google",
+					IPAddress:   "8.8.8.8",
+					ASN:         15169,
+					ASOrg:       "Google LLC",
+					NumResolved: 1,
+				},
+			},
+		}
+
+		// compare
+		if diff := cmp.Diff(expect, as.m); diff != "" {
+			t.Fatal(diff)
+		}
+	})
+}