chore: merge probe-engine into probe-cli (#201)

This is how I did it:

1. `git clone https://github.com/ooni/probe-engine internal/engine`

2. ```
(cd internal/engine && git describe --tags)
v0.23.0
```

3. `nvim go.mod` (merging `go.mod` with `internal/engine/go.mod`

4. `rm -rf internal/.git internal/engine/go.{mod,sum}`

5. `git add internal/engine`

6. `find . -type f -name \*.go -exec sed -i 's@/ooni/probe-engine@/ooni/probe-cli/v3/internal/engine@g' {} \;`

7. `go build ./...` (passes)

8. `go test -race ./...` (temporary failure on RiseupVPN)

9. `go mod tidy`

10. this commit message

Once this piece of work is done, we can build a new version of `ooniprobe` that
is using `internal/engine` directly. We need to do more work to ensure all the
other functionality in `probe-engine` (e.g. making mobile packages) are still WAI.

Part of https://github.com/ooni/probe/issues/1335

internal/engine/legacy/netxlogger/netxlogger.go

@@ -0,0 +1,173 @@
+// Package netxlogger is a logger for netx events.
+//
+// This package is a fork of github.com/ooni/netx/x/logger where
+// we applied ooni/probe-engine specific customisations.
+package netxlogger
+
+import (
+	"net/http"
+	"strings"
+
+	"github.com/ooni/probe-cli/v3/internal/engine/internal/tlsx"
+	"github.com/ooni/probe-cli/v3/internal/engine/legacy/netx/modelx"
+)
+
+// Logger is the interface we expect from a logger
+type Logger interface {
+	Debug(msg string)
+	Debugf(format string, v ...interface{})
+}
+
+// Handler is a handler that logs events.
+type Handler struct {
+	logger Logger
+}
+
+// NewHandler returns a new logging handler.
+func NewHandler(logger Logger) *Handler {
+	return &Handler{logger: logger}
+}
+
+// OnMeasurement logs the specific measurement
+func (h *Handler) OnMeasurement(m modelx.Measurement) {
+	// DNS
+	if m.ResolveStart != nil {
+		h.logger.Debugf(
+			"[httpTxID: %d] resolving: %s",
+			m.ResolveStart.TransactionID,
+			m.ResolveStart.Hostname,
+		)
+	}
+	if m.ResolveDone != nil {
+		h.logger.Debugf(
+			"[httpTxID: %d] resolve done: %s, %s",
+			m.ResolveDone.TransactionID,
+			fmtError(m.ResolveDone.Error),
+			m.ResolveDone.Addresses,
+		)
+	}
+
+	// Syscalls
+	if m.Connect != nil {
+		h.logger.Debugf(
+			"[httpTxID: %d] connect done: %s, %s (rtt=%s)",
+			m.Connect.TransactionID,
+			fmtError(m.Connect.Error),
+			m.Connect.RemoteAddress,
+			m.Connect.SyscallDuration,
+		)
+	}
+
+	// TLS
+	if m.TLSHandshakeStart != nil {
+		h.logger.Debugf(
+			"[httpTxID: %d] TLS handshake: (forceSNI='%s')",
+			m.TLSHandshakeStart.TransactionID,
+			m.TLSHandshakeStart.SNI,
+		)
+	}
+	if m.TLSHandshakeDone != nil {
+		h.logger.Debugf(
+			"[httpTxID: %d] TLS done: %s, %s (alpn='%s')",
+			m.TLSHandshakeDone.TransactionID,
+			fmtError(m.TLSHandshakeDone.Error),
+			tlsx.VersionString(m.TLSHandshakeDone.ConnectionState.Version),
+			m.TLSHandshakeDone.ConnectionState.NegotiatedProtocol,
+		)
+	}
+
+	// HTTP round trip
+	if m.HTTPRequestHeadersDone != nil {
+		proto := "HTTP/1.1"
+		for key := range m.HTTPRequestHeadersDone.Headers {
+			if strings.HasPrefix(key, ":") {
+				proto = "HTTP/2.0"
+				break
+			}
+		}
+		h.logger.Debugf(
+			"[httpTxID: %d] > %s %s %s",
+			m.HTTPRequestHeadersDone.TransactionID,
+			m.HTTPRequestHeadersDone.Method,
+			m.HTTPRequestHeadersDone.URL.RequestURI(),
+			proto,
+		)
+		if proto == "HTTP/2.0" {
+			h.logger.Debugf(
+				"[httpTxID: %d] > Host: %s",
+				m.HTTPRequestHeadersDone.TransactionID,
+				m.HTTPRequestHeadersDone.URL.Host,
+			)
+		}
+		for key, values := range m.HTTPRequestHeadersDone.Headers {
+			if strings.HasPrefix(key, ":") {
+				continue
+			}
+			for _, value := range values {
+				h.logger.Debugf(
+					"[httpTxID: %d] > %s: %s",
+					m.HTTPRequestHeadersDone.TransactionID,
+					key, value,
+				)
+			}
+		}
+		h.logger.Debugf(
+			"[httpTxID: %d] >", m.HTTPRequestHeadersDone.TransactionID)
+	}
+	if m.HTTPRequestDone != nil {
+		h.logger.Debugf(
+			"[httpTxID: %d] request sent; waiting for response",
+			m.HTTPRequestDone.TransactionID,
+		)
+	}
+	if m.HTTPResponseStart != nil {
+		h.logger.Debugf(
+			"[httpTxID: %d] start receiving response",
+			m.HTTPResponseStart.TransactionID,
+		)
+	}
+	if m.HTTPRoundTripDone != nil && m.HTTPRoundTripDone.Error == nil {
+		h.logger.Debugf(
+			"[httpTxID: %d] < %s %d %s",
+			m.HTTPRoundTripDone.TransactionID,
+			m.HTTPRoundTripDone.ResponseProto,
+			m.HTTPRoundTripDone.ResponseStatusCode,
+			http.StatusText(int(m.HTTPRoundTripDone.ResponseStatusCode)),
+		)
+		for key, values := range m.HTTPRoundTripDone.ResponseHeaders {
+			for _, value := range values {
+				h.logger.Debugf(
+					"[httpTxID: %d] < %s: %s",
+					m.HTTPRoundTripDone.TransactionID,
+					key, value,
+				)
+			}
+		}
+		h.logger.Debugf(
+			"[httpTxID: %d] <", m.HTTPRoundTripDone.TransactionID)
+	}
+
+	// HTTP response body
+	if m.HTTPResponseBodyPart != nil {
+		h.logger.Debugf(
+			"[httpTxID: %d] body part: %s, %d",
+			m.HTTPResponseBodyPart.TransactionID,
+			fmtError(m.HTTPResponseBodyPart.Error),
+			len(m.HTTPResponseBodyPart.Data),
+		)
+	}
+	if m.HTTPResponseDone != nil {
+		h.logger.Debugf(
+			"[httpTxID: %d] end of response",
+			m.HTTPResponseDone.TransactionID,
+		)
+	}
+}
+
+func fmtError(err error) (s string) {
+	s = "success"
+	if err != nil {
+		s = err.Error()
+	}
+	return
+}

internal/engine/legacy/netxlogger/netxlogger_test.go

@@ -0,0 +1,40 @@
+package netxlogger
+
+import (
+	"io/ioutil"
+	"net/http"
+	"testing"
+	"time"
+
+	"github.com/apex/log"
+	"github.com/apex/log/handlers/discard"
+	"github.com/ooni/probe-cli/v3/internal/engine/legacy/netx"
+	"github.com/ooni/probe-cli/v3/internal/engine/legacy/netx/modelx"
+)
+
+func TestGood(t *testing.T) {
+	log.SetHandler(discard.Default)
+	client := netx.NewHTTPClient()
+	client.ConfigureDNS("udp", "dns.google.com:53")
+	req, err := http.NewRequest("GET", "http://www.facebook.com", nil)
+	if err != nil {
+		t.Fatal(err)
+	}
+	req = req.WithContext(modelx.WithMeasurementRoot(req.Context(), &modelx.MeasurementRoot{
+		Beginning: time.Now(),
+		Handler:   NewHandler(log.Log),
+	}))
+	resp, err := client.HTTPClient.Do(req)
+	if err != nil {
+		t.Fatal(err)
+	}
+	if resp == nil {
+		t.Fatal("expected non-nil resp here")
+	}
+	defer resp.Body.Close()
+	_, err = ioutil.ReadAll(resp.Body)
+	if err != nil {
+		t.Fatal(err)
+	}
+	client.HTTPClient.CloseIdleConnections()
+}