gddo-server: add debug logs

Additional debug messages are added to the path for redirecting requests
to pkg.go.dev.

The response body is only logged for fetch requests. For other requests,
it will be the entire HTML page.

Change-Id: I61d67e08ae24485a28fc394959a1ca3f8459b46a
Reviewed-on: https://go-review.googlesource.com/c/gddo/+/284793
Trust: Julie Qiu <julie@golang.org>
Run-TryBot: Julie Qiu <julie@golang.org>
Reviewed-by: Jonathan Amsterdam <jba@google.com>

gddo-server/main.go

diff --git a/gddo-server/main.go b/gddo-server/main.go
index 63f0c1b..6c0c5c4 100644
--- a/gddo-server/main.go
+++ b/gddo-server/main.go
@@ -1079,31 +1079,34 @@
 		log.Printf("teeRequestToPkgGoDev(%q): not teeing request", r.URL.Path)
 		return
 	}
-	if strings.ToLower(os.Getenv("GDDO_TEE_REQUESTS_TO_PKGGODEV")) == "true" {
-		gddoEvent, pkggodevEvent := teeRequestToPkgGoDev(r, latency, s.isRobot(r), status)
-		payload := map[string]interface{}{
-			"godoc.org":  gddoEvent,
-			"pkg.go.dev": pkggodevEvent,
-		}
-
-		if s.gceLogger == nil {
-			for k, v := range payload {
-				log.Printf("%q", k)
-				log.Printf("%+v", v)
-			}
-			return
-		}
-		s.gceLogger.Log(logging.Entry{
-			HTTPRequest: &logging.HTTPRequest{
-				Request: r,
-				Latency: latency,
-				Status:  status,
-			},
-			Payload:  payload,
-			Severity: logging.Info,
-		})
+	val := os.Getenv("GDDO_TEE_REQUESTS_TO_PKGGODEV")
+	if strings.ToLower(val) != "true" {
+		log.Printf("not sending requests to pkg.go.dev (GDDO_TEE_REQUESTS_TO_PKGGODEV = %q)", val)
 		return
 	}
+
+	gddoEvent, pkggodevEvent := teeRequestToPkgGoDev(r, latency, s.isRobot(r), status)
+	payload := map[string]interface{}{
+		"godoc.org":  gddoEvent,
+		"pkg.go.dev": pkggodevEvent,
+	}
+	if s.gceLogger == nil {
+		for k, v := range payload {
+			log.Printf("%q", k)
+			log.Printf("%+v", v)
+		}
+		return
+	}
+	s.gceLogger.Log(logging.Entry{
+		HTTPRequest: &logging.HTTPRequest{
+			Request: r,
+			Latency: latency,
+			Status:  status,
+		},
+		Payload:  payload,
+		Severity: logging.Info,
+	})
+	return
 }
 
 func main() {

gddo-server/pkgsite.go

diff --git a/gddo-server/pkgsite.go b/gddo-server/pkgsite.go
index 5fa7ef0..3e185c9 100644
--- a/gddo-server/pkgsite.go
+++ b/gddo-server/pkgsite.go
@@ -10,6 +10,7 @@
 	"context"
 	"fmt"
 	"io/ioutil"
+	"log"
 	"net/http"
 	"net/url"
 	"path/filepath"
@@ -47,40 +48,46 @@
 		URL:  u.String(),
 	}
 	start := time.Now()
-	status, errResp := makeRequest(godocReq.Context(), u.String())
+	status, _, err := makeRequest(godocReq.Context(), u.String())
 	pkgEvent.Status = status
 	pkgEvent.Latency = time.Since(start)
-	// The response will always be an error here if not empty.
-	pkgEvent.Error = errResp
+	if err != nil {
+		pkgEvent.Error = err.Error()
+	}
 
 	if pkgEvent.Status == http.StatusNotFound && gddoEvent.Status == http.StatusOK {
 		// If the request was successful on godoc.org but returned a 404 on
 		// pkg.go.dev make a fetch request.
-		status, body := makeRequest(godocReq.Context(), "/fetch"+u.String())
+		status, body, err := makeRequest(godocReq.Context(), "/fetch"+u.String())
 		pkgEvent.FetchStatus = status
+		if err != nil {
+			pkgEvent.Error = err.Error()
+		}
 		pkgEvent.FetchResponse = body
 	}
 	return gddoEvent, pkgEvent
 }
 
-func makeRequest(ctx context.Context, url string) (int, string) {
+func makeRequest(ctx context.Context, url string) (int, string, error) {
 	req, err := http.NewRequest("GET", url, nil)
 	if err != nil {
-		return http.StatusInternalServerError, fmt.Sprintf("http.NewRequest: %v", err)
+		return http.StatusInternalServerError, "", fmt.Errorf("http.NewRequest: %v", err)
 	}
 	xfwd := req.Header.Get("X-Forwarded-for")
 	req.Header.Set("X-Godoc-Forwarded-for", xfwd)
+
+	log.Printf("sending request to pkg.go.dev: %q", url)
 	resp, err := ctxhttp.Do(ctx, http.DefaultClient, req)
 	if err != nil {
 		// Use StatusBadGateway to indicate the upstream error.
-		return http.StatusBadGateway, err.Error()
+		return http.StatusBadGateway, "", err
 	}
 	defer resp.Body.Close()
 	body, err := ioutil.ReadAll(resp.Body)
 	if err != nil {
-		return resp.StatusCode, fmt.Sprintf("can't read body: %v", err)
+		return resp.StatusCode, "", fmt.Errorf("can't read body: %v", err)
 	}
-	return resp.StatusCode, string(body)
+	return resp.StatusCode, string(body), nil
 }
 
 // doNotTeeURLsToPkgGoDev are paths that should not be teed to pkg.go.dev.