camget, httputil: more verbose HTTP debugging

Change-Id: I2fc1a1fe0fff99202245d391a8a76e9fab07adc2

cmd/camget/camget.go

@@ -43,6 +43,7 @@ import (
 	"io"
 	"io/ioutil"
 	"log"
+	"net"
 	"net/http"
 	"os"
 	"path/filepath"
@@ -105,6 +106,14 @@ func main() {
 	httpStats := &httputil.StatsTransport{
 		VerboseLog: *flagHTTP,
 	}
+	if *flagHTTP {
+		httpStats.Transport = &http.Transport{
+			Dial: func(net_, addr string) (net.Conn, error) {
+				log.Printf("Dialing %s", addr)
+				return net.Dial(net_, addr)
+			},
+		}
+	}
 	cl.SetHTTPClient(&http.Client{Transport: httpStats})
 
 	// Put a local disk cache in front of the HTTP client.

pkg/httputil/transport.go

@@ -20,6 +20,7 @@ import (
 	"log"
 	"net/http"
 	"sync"
+	"time"
 )
 
 // StatsTransport wraps another RoundTripper (or uses the default one) and
@@ -45,14 +46,26 @@ func (t *StatsTransport) Requests() int {
 func (t *StatsTransport) RoundTrip(req *http.Request) (resp *http.Response, err error) {
 	t.mu.Lock()
 	t.reqs++
+	n := t.reqs
 	t.mu.Unlock()
 
 	rt := t.Transport
 	if rt == nil {
 		rt = http.DefaultTransport
 	}
+	var t0 time.Time
 	if t.VerboseLog {
-		log.Printf("%s %s", req.Method, req.URL)
+		t0 = time.Now()
+		log.Printf("(%d) %s %s ...", n, req.Method, req.URL)
 	}
-	return rt.RoundTrip(req)
+	resp, err = rt.RoundTrip(req)
+	if t.VerboseLog {
+		td := time.Since(t0)
+		if err == nil {
+			log.Printf("(%d) %s %s = status %d (in %v)", n, req.Method, req.URL, resp.StatusCode, td)
+		} else {
+			log.Printf("(%d) %s %s = error: %v (in %v)", n, req.Method, req.URL, err, td)
+		}
+	}
+	return
 }