Skip to content

Commit

Permalink
fix(tracex): generate archival from single transaction-done event (#780)
Browse files Browse the repository at this point in the history 
Tracex contained some fragile code that assembled HTTP measurements
from scattered events, which worked because we were sure we were
performing a single measurement at any given time.

This diff restructures the code to emit a transaction-start and a
transaction-done events only. We have basically removed all the other
events (which we were not using). We kept the transaction-start
though, because it may be useful to see it when reading events. In
any case, what matters here is that we're now using the transaction-done
event aline to generate the archival HTTP measurement.

Hence, the original issue has been addressed. We will possibly
do more refactoring in the future, but for now this seems sufficient.

Part of ooni/probe#2121
  • Loading branch information
@bassosimone
bassosimone authored Jun 1, 2022
1 parent 153bfe1 commit 6212daa
Show file tree
Hide file tree
Showing 9 changed files with 339 additions and 682 deletions.
80 changes: 22 additions & 58 deletions internal/engine/experiment/urlgetter/getter_integration_test.go
View file
Original file line number Diff line number Diff line change
Expand Up @@ -37,18 +37,15 @@ func TestGetterWithVeryShortTimeout(t *testing.T) {
if tk.Failure == nil || *tk.Failure != "generic_timeout_error" {
t.Fatal("not the Failure we expected")
}
if len(tk.NetworkEvents) != 3 {
if len(tk.NetworkEvents) != 2 {
t.Fatal("not the NetworkEvents we expected")
}
if tk.NetworkEvents[0].Operation != "http_transaction_start" {
t.Fatal("not the NetworkEvents[0].Operation we expected")
}
if tk.NetworkEvents[1].Operation != "http_request_metadata" {
if tk.NetworkEvents[1].Operation != "http_transaction_done" {
t.Fatal("not the NetworkEvents[1].Operation we expected")
}
if tk.NetworkEvents[2].Operation != "http_transaction_done" {
t.Fatal("not the NetworkEvents[2].Operation we expected")
}
if len(tk.Queries) != 0 {
t.Fatal("not the Queries we expected")
}
Expand Down Expand Up @@ -104,18 +101,15 @@ func TestGetterWithCancelledContextVanilla(t *testing.T) {
if tk.Failure == nil || !strings.HasSuffix(*tk.Failure, "interrupted") {
t.Fatal("not the Failure we expected")
}
if len(tk.NetworkEvents) != 3 {
if len(tk.NetworkEvents) != 2 {
t.Fatal("not the NetworkEvents we expected")
}
if tk.NetworkEvents[0].Operation != "http_transaction_start" {
t.Fatal("not the NetworkEvents[0].Operation we expected")
}
if tk.NetworkEvents[1].Operation != "http_request_metadata" {
if tk.NetworkEvents[1].Operation != "http_transaction_done" {
t.Fatal("not the NetworkEvents[1].Operation we expected")
}
if tk.NetworkEvents[2].Operation != "http_transaction_done" {
t.Fatal("not the NetworkEvents[2].Operation we expected")
}
if len(tk.Queries) != 0 {
t.Fatal("not the Queries we expected")
}
Expand Down Expand Up @@ -172,18 +166,15 @@ func TestGetterWithCancelledContextAndMethod(t *testing.T) {
if tk.Failure == nil || !strings.HasSuffix(*tk.Failure, "interrupted") {
t.Fatal("not the Failure we expected")
}
if len(tk.NetworkEvents) != 3 {
if len(tk.NetworkEvents) != 2 {
t.Fatal("not the NetworkEvents we expected")
}
if tk.NetworkEvents[0].Operation != "http_transaction_start" {
t.Fatal("not the NetworkEvents[0].Operation we expected")
}
if tk.NetworkEvents[1].Operation != "http_request_metadata" {
if tk.NetworkEvents[1].Operation != "http_transaction_done" {
t.Fatal("not the NetworkEvents[1].Operation we expected")
}
if tk.NetworkEvents[2].Operation != "http_transaction_done" {
t.Fatal("not the NetworkEvents[2].Operation we expected")
}
if len(tk.Queries) != 0 {
t.Fatal("not the Queries we expected")
}
Expand Down Expand Up @@ -242,16 +233,13 @@ func TestGetterWithCancelledContextNoFollowRedirects(t *testing.T) {
if tk.Failure == nil || !strings.HasSuffix(*tk.Failure, "interrupted") {
t.Fatal("not the Failure we expected")
}
if len(tk.NetworkEvents) != 3 {
if len(tk.NetworkEvents) != 2 {
t.Fatal("not the NetworkEvents we expected")
}
if tk.NetworkEvents[0].Operation != "http_transaction_start" {
t.Fatal("not the NetworkEvents[0].Operation we expected")
}
if tk.NetworkEvents[1].Operation != "http_request_metadata" {
t.Fatal("not the NetworkEvents[1].Operation we expected")
}
if tk.NetworkEvents[2].Operation != "http_transaction_done" {
if tk.NetworkEvents[1].Operation != "http_transaction_done" {
t.Fatal("not the NetworkEvents[2].Operation we expected")
}
if len(tk.Queries) != 0 {
Expand Down Expand Up @@ -422,23 +410,18 @@ func TestGetterIntegrationHTTPS(t *testing.T) {
t.Fatal("not the Failure we expected")
}
var (
httpTransactionStart bool
httpRequestMetadata bool
resolveStart bool
resolveDone bool
connect bool
tlsHandshakeStart bool
tlsHandshakeDone bool
httpResponseMetadata bool
httpResponseBodySnapshot bool
httpTransactionDone bool
httpTransactionStart bool
resolveStart bool
resolveDone bool
connect bool
tlsHandshakeStart bool
tlsHandshakeDone bool
httpTransactionDone bool
)
for _, ev := range tk.NetworkEvents {
switch ev.Operation {
case "http_transaction_start":
httpTransactionStart = true
case "http_request_metadata":
httpRequestMetadata = true
case "resolve_start":
resolveStart = true
case "resolve_done":
Expand All @@ -449,24 +432,17 @@ func TestGetterIntegrationHTTPS(t *testing.T) {
tlsHandshakeStart = true
case "tls_handshake_done":
tlsHandshakeDone = true
case "http_response_metadata":
httpResponseMetadata = true
case "http_response_body_snapshot":
httpResponseBodySnapshot = true
case "http_transaction_done":
httpTransactionDone = true
}
}
ok := true
ok = ok && httpTransactionStart
ok = ok && httpRequestMetadata
ok = ok && resolveStart
ok = ok && resolveDone
ok = ok && connect
ok = ok && tlsHandshakeStart
ok = ok && tlsHandshakeDone
ok = ok && httpResponseMetadata
ok = ok && httpResponseBodySnapshot
ok = ok && httpTransactionDone
if !ok {
t.Fatal("not the NetworkEvents we expected")
Expand Down Expand Up @@ -657,23 +633,18 @@ func TestGetterHTTPSWithTunnel(t *testing.T) {
t.Fatal("not the Failure we expected")
}
var (
httpTransactionStart bool
httpRequestMetadata bool
resolveStart bool
resolveDone bool
connect bool
tlsHandshakeStart bool
tlsHandshakeDone bool
httpResponseMetadata bool
httpResponseBodySnapshot bool
httpTransactionDone bool
httpTransactionStart bool
resolveStart bool
resolveDone bool
connect bool
tlsHandshakeStart bool
tlsHandshakeDone bool
httpTransactionDone bool
)
for _, ev := range tk.NetworkEvents {
switch ev.Operation {
case "http_transaction_start":
httpTransactionStart = true
case "http_request_metadata":
httpRequestMetadata = true
case "resolve_start":
resolveStart = true
case "resolve_done":
Expand All @@ -684,24 +655,17 @@ func TestGetterHTTPSWithTunnel(t *testing.T) {
tlsHandshakeStart = true
case "tls_handshake_done":
tlsHandshakeDone = true
case "http_response_metadata":
httpResponseMetadata = true
case "http_response_body_snapshot":
httpResponseBodySnapshot = true
case "http_transaction_done":
httpTransactionDone = true
}
}
ok := true
ok = ok && httpTransactionStart
ok = ok && httpRequestMetadata
ok = ok && resolveStart == false
ok = ok && resolveDone == false
ok = ok && connect
ok = ok && tlsHandshakeStart
ok = ok && tlsHandshakeDone
ok = ok && httpResponseMetadata
ok = ok && httpResponseBodySnapshot
ok = ok && httpTransactionDone
if !ok {
t.Fatalf("not the NetworkEvents we expected: %+v", tk.NetworkEvents)
Expand Down
4 changes: 0 additions & 4 deletions internal/engine/netx/netx.go
View file
Original file line number Diff line number Diff line change
Expand Up @@ -187,10 +187,6 @@ func NewHTTPTransport(config Config) model.HTTPTransport {
txp = &netxlite.HTTPTransportLogger{Logger: config.Logger, HTTPTransport: txp}
}
if config.HTTPSaver != nil {
txp = &tracex.SaverMetadataHTTPTransport{
HTTPTransport: txp, Saver: config.HTTPSaver}
txp = &tracex.SaverBodyHTTPTransport{
HTTPTransport: txp, Saver: config.HTTPSaver}
txp = &tracex.SaverTransactionHTTPTransport{
HTTPTransport: txp, Saver: config.HTTPSaver}
}
Expand Down
15 changes: 2 additions & 13 deletions internal/engine/netx/netx_test.go
View file
Original file line number Diff line number Diff line change
Expand Up @@ -511,21 +511,10 @@ func TestNewWithSaver(t *testing.T) {
if stxptxp.Saver != saver {
t.Fatal("not the logger we expected")
}
sbtxp, ok := stxptxp.HTTPTransport.(*tracex.SaverBodyHTTPTransport)
if !ok {
t.Fatal("not the transport we expected")
}
if sbtxp.Saver != saver {
t.Fatal("not the logger we expected")
}
smtxp, ok := sbtxp.HTTPTransport.(*tracex.SaverMetadataHTTPTransport)
if !ok {
t.Fatal("not the transport we expected")
}
if smtxp.Saver != saver {
if stxptxp.Saver != saver {
t.Fatal("not the logger we expected")
}
if _, ok := smtxp.HTTPTransport.(*netxlite.HTTPTransportWrapper); !ok {
if _, ok := stxptxp.HTTPTransport.(*netxlite.HTTPTransportWrapper); !ok {
t.Fatal("not the transport we expected")
}
}
Expand Down
17 changes: 5 additions & 12 deletions internal/engine/netx/tracex/archival.go
View file
Original file line number Diff line number Diff line change
Expand Up @@ -106,6 +106,8 @@ func httpAddHeaders(
destList *[]HTTPHeader,
destMap *map[string]MaybeBinaryValue,
) {
*destList = []HTTPHeader{}
*destMap = make(map[string]model.ArchivalMaybeBinaryData)
for key, values := range source {
for index, value := range values {
value := MaybeBinaryValue{Value: value}
Expand Down Expand Up @@ -144,29 +146,20 @@ func newRequestList(begin time.Time, events []Event) []RequestEntry {
for _, wrapper := range events {
ev := wrapper.Value()
switch wrapper.(type) {
case *EventHTTPTransactionStart:
case *EventHTTPTransactionDone:
entry = RequestEntry{}
entry.T = ev.Time.Sub(begin).Seconds()
case *EventHTTPRequestBodySnapshot:
entry.Request.Body.Value = string(ev.Data)
entry.Request.BodyIsTruncated = ev.DataIsTruncated
case *EventHTTPRequestMetadata:
entry.Request.Headers = make(map[string]MaybeBinaryValue)
httpAddHeaders(
ev.HTTPRequestHeaders, &entry.Request.HeadersList, &entry.Request.Headers)
entry.Request.Method = ev.HTTPMethod
entry.Request.URL = ev.HTTPURL
entry.Request.Transport = ev.Transport
case *EventHTTPResponseMetadata:
entry.Response.Headers = make(map[string]MaybeBinaryValue)
httpAddHeaders(
ev.HTTPResponseHeaders, &entry.Response.HeadersList, &entry.Response.Headers)
entry.Response.Code = int64(ev.HTTPStatusCode)
entry.Response.Locations = ev.HTTPResponseHeaders.Values("Location")
case *EventHTTPResponseBodySnapshot:
entry.Response.Body.Value = string(ev.Data)
entry.Response.BodyIsTruncated = ev.DataIsTruncated
case *EventHTTPTransactionDone:
entry.Response.Body.Value = string(ev.HTTPResponseBody)
entry.Response.BodyIsTruncated = ev.HTTPResponseBodyIsTruncated
entry.Failure = NewFailure(ev.Err)
out = append(out, entry)
}
Expand Down
40 changes: 17 additions & 23 deletions internal/engine/netx/tracex/archival_test.go
View file
Original file line number Diff line number Diff line change
Expand Up @@ -143,35 +143,27 @@ func TestNewRequestList(t *testing.T) {
name: "realistic run",
args: args{
begin: begin,
events: []Event{&EventHTTPTransactionStart{&EventValue{
Time: begin.Add(10 * time.Millisecond),
}}, &EventHTTPRequestBodySnapshot{&EventValue{
Data: []byte("deadbeef"),
DataIsTruncated: false,
}}, &EventHTTPRequestMetadata{&EventValue{
events: []Event{&EventHTTPTransactionDone{&EventValue{
HTTPRequestHeaders: http.Header{
"User-Agent": []string{"miniooni/0.1.0-dev"},
},
HTTPMethod: "POST",
HTTPURL: "https://www.example.com/submit",
}}, &EventHTTPResponseMetadata{&EventValue{
HTTPResponseHeaders: http.Header{
"Server": []string{"miniooni/0.1.0-dev"},
},
HTTPStatusCode: 200,
}}, &EventHTTPResponseBodySnapshot{&EventValue{
Data: []byte("{}"),
DataIsTruncated: false,
}}, &EventHTTPTransactionDone{&EventValue{}}, &EventHTTPTransactionStart{&EventValue{
Time: begin.Add(20 * time.Millisecond),
}}, &EventHTTPRequestMetadata{&EventValue{
HTTPStatusCode: 200,
HTTPResponseBody: []byte("{}"),
HTTPResponseBodyIsTruncated: false,
Time: begin.Add(10 * time.Millisecond),
}}, &EventHTTPTransactionDone{&EventValue{
HTTPRequestHeaders: http.Header{
"User-Agent": []string{"miniooni/0.1.0-dev"},
},
HTTPMethod: "GET",
HTTPURL: "https://www.example.com/result",
}}, &EventHTTPTransactionDone{&EventValue{
Err: io.EOF,
Err: io.EOF,
Time: begin.Add(20 * time.Millisecond),
}}},
},
want: []RequestEntry{{
Expand All @@ -189,11 +181,15 @@ func TestNewRequestList(t *testing.T) {
Method: "GET",
URL: "https://www.example.com/result",
},
Response: HTTPResponse{
HeadersList: []HTTPHeader{},
Headers: make(map[string]MaybeBinaryValue),
},
T: 0.02,
}, {
Request: HTTPRequest{
Body: MaybeBinaryValue{
Value: "deadbeef",
Value: "",
},
HeadersList: []HTTPHeader{{
Key: "User-Agent",
Expand Down Expand Up @@ -231,21 +227,19 @@ func TestNewRequestList(t *testing.T) {
name: "run with redirect and headers to sort",
args: args{
begin: begin,
events: []Event{&EventHTTPTransactionStart{&EventValue{
Time: begin.Add(10 * time.Millisecond),
}}, &EventHTTPRequestMetadata{&EventValue{
events: []Event{&EventHTTPTransactionDone{&EventValue{
HTTPRequestHeaders: http.Header{
"User-Agent": []string{"miniooni/0.1.0-dev"},
},
HTTPMethod: "GET",
HTTPURL: "https://www.example.com/",
}}, &EventHTTPResponseMetadata{&EventValue{
HTTPResponseHeaders: http.Header{
"Server": []string{"miniooni/0.1.0-dev"},
"Location": []string{"https://x.example.com", "https://y.example.com"},
},
HTTPStatusCode: 302,
}}, &EventHTTPTransactionDone{&EventValue{}}},
Time: begin.Add(10 * time.Millisecond),
}}},
},
want: []RequestEntry{{
Request: HTTPRequest{
Expand Down Expand Up @@ -293,7 +287,7 @@ func TestNewRequestList(t *testing.T) {
for _, tt := range tests {
t.Run(tt.name, func(t *testing.T) {
if got := NewRequestList(tt.args.begin, tt.args.events); !reflect.DeepEqual(got, tt.want) {
t.Error(cmp.Diff(got, tt.want))
t.Error(cmp.Diff(tt.want, got))
}
})
}
Expand Down
Loading

0 comments on commit 6212daa

Please sign in to comment.