Refactor metric prints

2 files changed, 122 insertions, 24 deletions

diff --git a/internal/qna/qna.go b/internal/qna/qna.go
index bd2078d..809df15 100644
--- a/internal/qna/qna.go
+++ b/internal/qna/qna.go
@@ -1,12 +1,119 @@
 package qna
 
+import (
+	"fmt"
+	"net"
+	"net/url"
+)
+
 type Question struct {
 	Domain string // domain name to visit via HTTPS
 }
 
 type Answer struct {
 	Domain string // domain name of the visited HTTPS site
-	OK     bool   // true if HTTP GET request succeeded
 	HTTP   string // value set in the Onion-Location HTTP header (if any)
 	HTML   string // value set in the Onion-Location HTML attribute (if any)
+
+	ReqErr error // nil if HTTP GET request could be constructed
+	DoErr  error // nil if HTTP GET request could be executed
+}
+
+func (a Answer) String() string {
+	if a.ReqErr != nil {
+		return fmt.Sprintf("%s: %v", a.ReqErr)
+	}
+	if a.DoErr != nil {
+		return fmt.Sprintf("%s: %v", a.DoErr)
+	}
+	if a.HTTP == "" && a.HTML == "" {
+		return fmt.Sprintf("%s: connected but found no Onion-Location")
+	}
+	return fmt.Sprintf("%s header=%s attribute=%s", a.Domain, a.HTTP, a.HTML)
+}
+
+type Progress struct {
+	NumReqErr int // error before sending requests
+	NumDoErr  int // error while sending request
+	NumOK     int // got response
+	NumOnion  int // found onion in response
+
+	// More details about DNS errors while sending request
+	NumDNSNotFound int
+	NumDNSTimeout  int
+	NumDNSOther    int
+}
+
+func (p Progress) String() string {
+	str := fmt.Sprintf("  Processed: %d\n", p.NumAnswer())
+	str += fmt.Sprintf("    Success: %d (Onion-Location:%d)\n", p.NumOK, p.NumOnion)
+	str += fmt.Sprintf("    Failure: %d (Req:%d Do:%d)\n", p.NumError(), p.NumReqErr, p.NumDoErr)
+	str += fmt.Sprintf("        DNS: %d (NotFound:%d Timeout:%d Other:%d)",
+		p.NumDNSErr(), p.NumDNSNotFound, p.NumDNSTimeout, p.NumDNSOther)
+	return str
+}
+
+func (p *Progress) NumAnswer() int {
+	return p.NumReqErr + p.NumDoErr + p.NumOK
+}
+
+func (p *Progress) NumError() int {
+	return p.NumReqErr + p.NumDoErr
+}
+
+func (p *Progress) NumDNSErr() int {
+	return p.NumDNSNotFound + p.NumDNSTimeout + p.NumDNSOther
+}
+
+func (p *Progress) AddAnswer(a Answer) {
+	if a.ReqErr != nil {
+		p.NumReqErr += 1
+		return
+	}
+	if a.DoErr != nil {
+		p.NumDoErr += 1
+		err := dnsError(a.DoErr)
+		if err == nil {
+			return
+		}
+
+		if err.IsTimeout {
+			p.NumDNSTimeout += 1
+		} else if err.IsNotFound {
+			p.NumDNSNotFound += 1
+		} else {
+			p.NumDNSOther += 1
+		}
+		return
+	}
+
+	p.NumOK += 1
+	if a.HTTP != "" || a.HTML != "" {
+		p.NumOnion += 1
+	}
+}
+
+func dnsError(err error) *net.DNSError {
+	if err == nil {
+		return nil
+	}
+
+	urlErr, ok := err.(*url.Error)
+	if !ok {
+		return nil
+	}
+
+	err = urlErr.Err
+	opErr, ok := err.(*net.OpError)
+	if !ok {
+		return nil
+	}
+
+	err = opErr.Err
+	dnsErr, ok := err.(*net.DNSError)
+	if !ok {
+		return nil
+	}
+
+	return dnsErr
 }
diff --git a/main.go b/main.go
index 784638d..827eeb2 100644
--- a/main.go
+++ b/main.go
@@ -119,17 +119,18 @@ func work(ctx context.Context, opts *options.Options, cli *http.Client, question
 	answer := qna.Answer{Domain: question.Domain}
 	req, err := http.NewRequestWithContext(cctx, http.MethodGet, "https://"+question.Domain, nil)
 	if err != nil {
+		answer.ReqErr = err
 		answerCh <- answer
 		return
 	}
 
 	rsp, err := cli.Do(req)
 	if err != nil {
+		answer.DoErr = err
 		answerCh <- answer
 		return
 	}
 	defer rsp.Body.Close()
-	answer.OK = true
 
 	onion, ok := onionloc.HTTP(rsp)
 	if ok {
@@ -143,29 +144,16 @@ func work(ctx context.Context, opts *options.Options, cli *http.Client, question
 }
 
 func workAggregator(ctx context.Context, opts options.Options, answerCh chan qna.Answer) {
-	numConnect := 0
-	numOnions := 0
-	numAll := 0
-	output := func(prefix string) {
-		log.Printf("%s: %d/%d connected, %d sites configured Onion-Location\n", prefix, numConnect, numAll, numOnions)
-	}
+	p := qna.Progress{}
 	handleAnswer := func(a qna.Answer) {
-		numAll += 1
-		if !a.OK {
-			return
-		}
-
-		numConnect += 1
+		p.AddAnswer(a)
 		if a.HTTP != "" || a.HTML != "" {
-			numOnions += 1
-			fmt.Printf("%s header=%s attribute=%s\n", a.Domain, a.HTTP, a.HTML)
+			fmt.Printf("%s\n", a.String())
 		}
 	}
 
 	metrics := time.NewTicker(opts.MetricsInterval)
 	defer metrics.Stop()
-
-	defer output("SUMMARY")
 	for {
 		select {
 		case <-ctx.Done():
@@ -175,13 +163,14 @@ func workAggregator(ctx context.Context, opts options.Options, answerCh chan qna
 				case a := <-answerCh:
 					handleAnswer(a)
 				case <-time.After(opts.Timeout + time.Second):
+					log.Printf("INFO: metrics@aggregator: summary: \n\n%s\n\n", p.String())
 					return
 				}
 			}
 		case a := <-answerCh:
 			handleAnswer(a)
 		case <-metrics.C:
-			output("INFO")
+			log.Printf("INFO: metrics@aggregator: \n\n%s\n\n", p.String())
 		}
 	}
 }
@@ -242,11 +231,13 @@ func workGenerator(ctx context.Context, opts options.Options, fp *os.File, quest
 			readCount++
 		case <-metrics.C:
 			now := time.Now().Unix()
-			log.Printf("INFO: currently %.1f sites/s, %.1f sites/s since start, at line %d\n",
-				float64(nextLine-latestCount)/float64(now-latestTime),
-				float64(nextLine-opts.StartLineInclusive)/float64(now-startTime),
-				nextLine,
-			)
+			currRate := float64(nextLine-latestCount) / float64(now-latestTime)
+			avgRate := float64(nextLine-opts.StartLineInclusive) / float64(now-startTime)
+
+			str := fmt.Sprintf("  Current rate: %.1f sites/s\n", currRate)
+			str += fmt.Sprintf("  Average rate: %.1f sites/s\n", avgRate)
+			str += fmt.Sprintf("     Next line: %d\n", nextLine)
+			log.Printf("INFO: metrics@generator:\n\n%s\n\n", str)
 
 			latestCount = nextLine
 			latestTime = now