netx: restructure http events for easy saving in OONI format

netx/httptransport/httptransport.go

@@ -131,10 +131,12 @@ func New(config Config) RoundTripper {
 		txp = LoggingTransport{Logger: config.Logger, RoundTripper: txp}
 	}
 	if config.HTTPSaver != nil {
+		txp = SaverMetadataHTTPTransport{RoundTripper: txp, Saver: config.HTTPSaver}
 		txp = SaverBodyHTTPTransport{RoundTripper: txp, Saver: config.HTTPSaver}
-		txp = SaverRoundTripHTTPTransport{RoundTripper: txp, Saver: config.HTTPSaver}
 		txp = SaverPerformanceHTTPTransport{
 			RoundTripper: txp, Saver: config.HTTPSaver}
+		txp = SaverTransactionHTTPTransport{
+			RoundTripper: txp, Saver: config.HTTPSaver}
 	}
 	txp = UserAgentTransport{RoundTripper: txp}
 	return txp

netx/httptransport/saver.go

@@ -39,30 +39,53 @@ func (txp SaverPerformanceHTTPTransport) RoundTrip(req *http.Request) (*http.Res
 	return txp.RoundTripper.RoundTrip(req)
 }
 
-// SaverRoundTripHTTPTransport is a RoundTripper that saves base
-// events pertaining to the HTTP round trip
-type SaverRoundTripHTTPTransport struct {
+// SaverMetadataHTTPTransport is a RoundTripper that saves
+// events related to HTTP request and response metadata
+type SaverMetadataHTTPTransport struct {
 	RoundTripper
 	Saver *trace.Saver
 }
 
 // RoundTrip implements RoundTripper.RoundTrip
-func (txp SaverRoundTripHTTPTransport) RoundTrip(req *http.Request) (*http.Response, error) {
-	start := time.Now()
+func (txp SaverMetadataHTTPTransport) RoundTrip(req *http.Request) (*http.Response, error) {
 	txp.Saver.Write(trace.Event{
-		HTTPRequest: req,
-		Name:        "http_round_trip_start",
-		Time:        start,
+		HTTPHeaders: req.Header,
+		HTTPMethod:  req.Method,
+		HTTPURL:     req.URL.String(),
+		Name:        "http_request_metadata",
+		Time:        time.Now(),
+	})
+	resp, err := txp.RoundTripper.RoundTrip(req)
+	if err != nil {
+		return nil, err
+	}
+	txp.Saver.Write(trace.Event{
+		HTTPHeaders:    resp.Header,
+		HTTPStatusCode: resp.StatusCode,
+		Name:           "http_response_metadata",
+		Time:           time.Now(),
+	})
+	return resp, err
+}
+
+// SaverTransactionHTTPTransport is a RoundTripper that saves
+// events related to the HTTP transaction
+type SaverTransactionHTTPTransport struct {
+	RoundTripper
+	Saver *trace.Saver
+}
+
+// RoundTrip implements RoundTripper.RoundTrip
+func (txp SaverTransactionHTTPTransport) RoundTrip(req *http.Request) (*http.Response, error) {
+	txp.Saver.Write(trace.Event{
+		Name: "http_transaction_start",
+		Time: time.Now(),
 	})
 	resp, err := txp.RoundTripper.RoundTrip(req)
-	stop := time.Now()
 	txp.Saver.Write(trace.Event{
-		Duration:     stop.Sub(start),
-		Err:          err,
-		HTTPRequest:  req,
-		HTTPResponse: resp,
-		Name:         "http_round_trip_done",
-		Time:         stop,
+		Err:  err,
+		Name: "http_transaction_done",
+		Time: time.Now(),
 	})
 	return resp, err
 }
@@ -128,5 +151,6 @@ type saverReadCloser struct {
 }
 
 var _ RoundTripper = SaverPerformanceHTTPTransport{}
-var _ RoundTripper = SaverRoundTripHTTPTransport{}
+var _ RoundTripper = SaverMetadataHTTPTransport{}
 var _ RoundTripper = SaverBodyHTTPTransport{}
+var _ RoundTripper = SaverTransactionHTTPTransport{}

netx/httptransport/saver_test.go

@@ -12,71 +12,156 @@ import (
 	"github.com/ooni/probe-engine/netx/trace"
 )
 
-func TestUnitSaverRoundTripFailure(t *testing.T) {
-	expected := errors.New("mocked error")
+func TestIntegrationSaverPerformanceNoMultipleEvents(t *testing.T) {
+	if testing.Short() {
+		t.Skip("skipping test in short mode")
+	}
 	saver := &trace.Saver{}
-	txp := httptransport.SaverRoundTripHTTPTransport{
-		RoundTripper: httptransport.FakeTransport{
-			Err: expected,
-		},
-		Saver: saver,
+	// register twice - do we see events twice?
+	txp := httptransport.SaverPerformanceHTTPTransport{
+		RoundTripper: http.DefaultTransport.(*http.Transport),
+		Saver:        saver,
 	}
-	req, err := http.NewRequest("GET", "http://www.google.com", nil)
+	txp = httptransport.SaverPerformanceHTTPTransport{
+		RoundTripper: txp,
+		Saver:        saver,
+	}
+	req, err := http.NewRequest("GET", "https://www.google.com", nil)
 	if err != nil {
 		t.Fatal(err)
 	}
 	resp, err := txp.RoundTrip(req)
-	if !errors.Is(err, expected) {
+	if err != nil {
 		t.Fatal("not the error we expected")
 	}
-	if resp != nil {
-		t.Fatal("expected nil response here")
+	if resp == nil {
+		t.Fatal("expected non nil response here")
+	}
+	ev := saver.Read()
+	// we should specifically see the events not attached to any
+	// context being submitted twice. This is fine because they are
+	// explicit, while the context is implicit and hence leads to
+	// more subtle bugs. For example, this happens when you measure
+	// every event and combine HTTP with DoH.
+	if len(ev) != 3 {
+		t.Fatal("expected three events")
+	}
+	expected := []string{
+		"http_wrote_headers",       // measured with context
+		"http_wrote_request",       // measured with context
+		"http_first_response_byte", // measured with context
+	}
+	for i := 0; i < len(expected); i++ {
+		if ev[i].Name != expected[i] {
+			t.Fatal("unexpected event name")
+		}
+	}
+}
+
+func TestIntegrationSaverMetadataSuccess(t *testing.T) {
+	if testing.Short() {
+		t.Skip("skipping test in short mode")
+	}
+	saver := &trace.Saver{}
+	txp := httptransport.SaverMetadataHTTPTransport{
+		RoundTripper: http.DefaultTransport.(*http.Transport),
+		Saver:        saver,
+	}
+	req, err := http.NewRequest("GET", "https://www.google.com", nil)
+	if err != nil {
+		t.Fatal(err)
+	}
+	req.Header.Add("User-Agent", "miniooni/0.1.0-dev")
+	resp, err := txp.RoundTrip(req)
+	if err != nil {
+		t.Fatal("not the error we expected")
+	}
+	if resp == nil {
+		t.Fatal("expected non nil response here")
 	}
 	ev := saver.Read()
 	if len(ev) != 2 {
 		t.Fatal("expected two events")
 	}
-	if ev[0].HTTPRequest.Method != "GET" {
+	//
+	if ev[0].HTTPMethod != "GET" {
 		t.Fatal("unexpected Method")
 	}
-	if ev[0].HTTPRequest.URL.String() != "http://www.google.com" {
+	if len(ev[0].HTTPHeaders) <= 0 {
+		t.Fatal("unexpected Headers")
+	}
+	if ev[0].HTTPURL != "https://www.google.com" {
 		t.Fatal("unexpected URL")
 	}
-	if ev[0].Name != "http_round_trip_start" {
+	if ev[0].Name != "http_request_metadata" {
 		t.Fatal("unexpected Name")
 	}
 	if !ev[0].Time.Before(time.Now()) {
 		t.Fatal("unexpected Time")
 	}
-	if ev[1].Duration <= 0 {
-		t.Fatal("unexpected Duration")
+	//
+	if ev[1].HTTPStatusCode != 200 {
+		t.Fatal("unexpected StatusCode")
+	}
+	if len(ev[1].HTTPHeaders) <= 0 {
+		t.Fatal("unexpected Headers")
 	}
-	if !errors.Is(ev[1].Err, expected) {
-		t.Fatal("unexpected Err")
+	if ev[1].Name != "http_response_metadata" {
+		t.Fatal("unexpected Name")
+	}
+	if !ev[1].Time.After(ev[0].Time) {
+		t.Fatal("unexpected Time")
+	}
+}
+
+func TestUnitSaverMetadataFailure(t *testing.T) {
+	expected := errors.New("mocked error")
+	saver := &trace.Saver{}
+	txp := httptransport.SaverMetadataHTTPTransport{
+		RoundTripper: httptransport.FakeTransport{
+			Err: expected,
+		},
+		Saver: saver,
+	}
+	req, err := http.NewRequest("GET", "http://www.google.com", nil)
+	if err != nil {
+		t.Fatal(err)
 	}
-	if ev[1].HTTPRequest.Method != "GET" {
+	req.Header.Add("User-Agent", "miniooni/0.1.0-dev")
+	resp, err := txp.RoundTrip(req)
+	if !errors.Is(err, expected) {
+		t.Fatal("not the error we expected")
+	}
+	if resp != nil {
+		t.Fatal("expected nil response here")
+	}
+	ev := saver.Read()
+	if len(ev) != 1 {
+		t.Fatal("expected one event")
+	}
+	if ev[0].HTTPMethod != "GET" {
 		t.Fatal("unexpected Method")
 	}
-	if ev[1].HTTPRequest.URL.String() != "http://www.google.com" {
-		t.Fatal("unexpected URL")
+	if len(ev[0].HTTPHeaders) <= 0 {
+		t.Fatal("unexpected Headers")
 	}
-	if ev[1].HTTPResponse != nil {
-		t.Fatal("unexpected HTTPResponse")
+	if ev[0].HTTPURL != "http://www.google.com" {
+		t.Fatal("unexpected URL")
 	}
-	if ev[1].Name != "http_round_trip_done" {
+	if ev[0].Name != "http_request_metadata" {
 		t.Fatal("unexpected Name")
 	}
-	if !ev[1].Time.After(ev[0].Time) {
+	if !ev[0].Time.Before(time.Now()) {
 		t.Fatal("unexpected Time")
 	}
 }
 
-func TestIntegrationSaverRoundTripSuccess(t *testing.T) {
+func TestIntegrationSaverTransactionSuccess(t *testing.T) {
 	if testing.Short() {
 		t.Skip("skipping test in short mode")
 	}
 	saver := &trace.Saver{}
-	txp := httptransport.SaverRoundTripHTTPTransport{
+	txp := httptransport.SaverTransactionHTTPTransport{
 		RoundTripper: http.DefaultTransport.(*http.Transport),
 		Saver:        saver,
 	}
@@ -96,85 +181,62 @@ func TestIntegrationSaverRoundTripSuccess(t *testing.T) {
 		t.Fatal("expected two events")
 	}
 	//
-	if ev[0].HTTPRequest.Method != "GET" {
-		t.Fatal("unexpected Method")
-	}
-	if ev[0].HTTPRequest.URL.String() != "https://www.google.com" {
-		t.Fatal("unexpected URL")
-	}
-	if ev[0].Name != "http_round_trip_start" {
+	if ev[0].Name != "http_transaction_start" {
 		t.Fatal("unexpected Name")
 	}
 	if !ev[0].Time.Before(time.Now()) {
 		t.Fatal("unexpected Time")
 	}
 	//
-	if ev[1].Duration <= 0 {
-		t.Fatal("unexpected Duration")
-	}
 	if ev[1].Err != nil {
 		t.Fatal("unexpected Err")
 	}
-	if ev[1].HTTPRequest.Method != "GET" {
-		t.Fatal("unexpected Method")
-	}
-	if ev[1].HTTPRequest.URL.String() != "https://www.google.com" {
-		t.Fatal("unexpected URL")
-	}
-	if ev[1].HTTPResponse.StatusCode != 200 {
-		t.Fatal("unexpected StatusCode")
-	}
-	if ev[1].Name != "http_round_trip_done" {
+	if ev[1].Name != "http_transaction_done" {
 		t.Fatal("unexpected Name")
 	}
 	if !ev[1].Time.After(ev[0].Time) {
 		t.Fatal("unexpected Time")
 	}
 }
 
-func TestIntegrationSaverPerformanceNoMultipleEvents(t *testing.T) {
-	if testing.Short() {
-		t.Skip("skipping test in short mode")
-	}
+func TestUnitSaverTransactionFailure(t *testing.T) {
+	expected := errors.New("mocked error")
 	saver := &trace.Saver{}
-	// register twice - do we see events twice?
-	txp := httptransport.SaverPerformanceHTTPTransport{
-		RoundTripper: http.DefaultTransport.(*http.Transport),
-		Saver:        saver,
-	}
-	txp = httptransport.SaverPerformanceHTTPTransport{
-		RoundTripper: txp,
-		Saver:        saver,
+	txp := httptransport.SaverTransactionHTTPTransport{
+		RoundTripper: httptransport.FakeTransport{
+			Err: expected,
+		},
+		Saver: saver,
 	}
-	req, err := http.NewRequest("GET", "https://www.google.com", nil)
+	req, err := http.NewRequest("GET", "http://www.google.com", nil)
 	if err != nil {
 		t.Fatal(err)
 	}
 	resp, err := txp.RoundTrip(req)
-	if err != nil {
+	if !errors.Is(err, expected) {
 		t.Fatal("not the error we expected")
 	}
-	if resp == nil {
-		t.Fatal("expected non nil response here")
+	if resp != nil {
+		t.Fatal("expected nil response here")
 	}
 	ev := saver.Read()
-	// we should specifically see the events not attached to any
-	// context being submitted twice. This is fine because they are
-	// explicit, while the context is implicit and hence leads to
-	// more subtle bugs. For example, this happens when you measure
-	// every event and combine HTTP with DoH.
-	if len(ev) != 3 {
-		t.Fatal("expected three events")
+	if len(ev) != 2 {
+		t.Fatal("expected two events")
 	}
-	expected := []string{
-		"http_wrote_headers",       // measured with context
-		"http_wrote_request",       // measured with context
-		"http_first_response_byte", // measured with context
+	if ev[0].Name != "http_transaction_start" {
+		t.Fatal("unexpected Name")
 	}
-	for i := 0; i < len(expected); i++ {
-		if ev[i].Name != expected[i] {
-			t.Fatal("unexpected event name")
-		}
+	if !ev[0].Time.Before(time.Now()) {
+		t.Fatal("unexpected Time")
+	}
+	if ev[1].Name != "http_transaction_done" {
+		t.Fatal("unexpected Name")
+	}
+	if !errors.Is(ev[1].Err, expected) {
+		t.Fatal("unexpected Err")
+	}
+	if !ev[1].Time.After(ev[0].Time) {
+		t.Fatal("unexpected Time")
 	}
 }