bug: propagate TLS errors as failures

go.mod

@@ -13,25 +13,24 @@ require (
 	github.com/google/gopacket v1.1.19
 	github.com/google/martian v2.1.0+incompatible
 	github.com/google/uuid v1.3.0
-	github.com/gorilla/websocket v1.5.0
 	github.com/jackpal/gateway v1.0.11 // pinned to a previous version until we can use go1.21
-	github.com/m-lab/ndt7-client-go v0.7.0
 	github.com/ory/dockertest/v3 v3.9.1
 	github.com/refraction-networking/utls v1.3.1
 	gitlab.com/yawning/obfs4.git v0.0.0-20220904064028-336a71d6e4cf
 	golang.org/x/net v0.22.0
 	golang.org/x/sync v0.6.0
-	golang.zx2c4.com/wireguard v0.0.0-20231211153847-12269c276173
+	golang.zx2c4.com/wireguard v0.0.0-20231211153847-12269c276173 // indirect
 )
 
+require golang.org/x/exp v0.0.0-20240325151524-a685a6edb6d8
+
 require (
 	filippo.io/edwards25519 v1.0.0-rc.1.0.20210721174708-390f27c3be20 // indirect
 	github.com/Azure/go-ansiterm v0.0.0-20170929234023-d6e3b3328b78 // indirect
 	github.com/Doridian/gopacket v1.2.1 // indirect
 	github.com/Microsoft/go-winio v0.6.0 // indirect
 	github.com/Nvveen/Gotty v0.0.0-20120604004816-cd527374f1e5 // indirect
 	github.com/andybalholm/brotli v1.0.4 // indirect
-	github.com/araddon/dateparse v0.0.0-20200409225146-d820a6159ab1 // indirect
 	github.com/cenkalti/backoff/v4 v4.1.3 // indirect
 	github.com/containerd/continuity v0.3.0 // indirect
 	github.com/davecgh/go-spew v1.1.1 // indirect
@@ -45,10 +44,7 @@ require (
 	github.com/google/shlex v0.0.0-20191202100458-e7afc7fbc510 // indirect
 	github.com/imdario/mergo v0.3.12 // indirect
 	github.com/klauspost/compress v1.15.15 // indirect
-	github.com/m-lab/go v0.1.43 // indirect
-	github.com/m-lab/locate v0.4.1 // indirect
-	github.com/m-lab/ndt-server v0.20.2 // indirect
-	github.com/m-lab/tcp-info v1.5.2 // indirect
+	github.com/kr/text v0.2.0 // indirect
 	github.com/mitchellh/mapstructure v1.4.1 // indirect
 	github.com/moby/term v0.0.0-20201216013528-df9cb8a40635 // indirect
 	github.com/opencontainers/go-digest v1.0.0 // indirect
@@ -64,13 +60,12 @@ require (
 	github.com/xeipuuv/gojsonschema v1.2.0 // indirect
 	gitlab.com/yawning/edwards25519-extra.git v0.0.0-20211229043746-2f91fcc9fbdb // indirect
 	golang.org/x/crypto v0.21.0 // indirect
-	golang.org/x/exp v0.0.0-20240325151524-a685a6edb6d8 // indirect
 	golang.org/x/mod v0.16.0 // indirect
 	golang.org/x/sys v0.18.0 // indirect
 	golang.org/x/time v0.3.0 // indirect
 	golang.org/x/tools v0.19.0 // indirect
 	golang.zx2c4.com/wintun v0.0.0-20230126152724-0fa3db229ce2 // indirect
 	gopkg.in/yaml.v2 v2.4.0 // indirect
 	gopkg.in/yaml.v3 v3.0.1 // indirect
-	gvisor.dev/gvisor v0.0.0-20230927004350-cbd86285d259 // indirect
+	gotest.tools/v3 v3.4.0 // indirect
 )

internal/model/mocks.go

@@ -2,6 +2,7 @@
 
 import "fmt"
 
+// TestLogger is a logger that can be used whenever a test needs a logger to be passed around.
 type TestLogger struct {
 	Lines []string
 }
@@ -10,26 +11,37 @@
 	tl.Lines = append(tl.Lines, msg)
 }
 
+// Debug implements model.Logger
 func (tl *TestLogger) Debug(msg string) {
 	tl.append(msg)
 }
+
+// Debugf implements model.Logger
 func (tl *TestLogger) Debugf(format string, v ...any) {
 	tl.append(fmt.Sprintf(format, v...))
 }
+
+// Info implements model.Logger
 func (tl *TestLogger) Info(msg string) {
 	tl.append(msg)
 }
+
+// Infof implements model.Logger
 func (tl *TestLogger) Infof(format string, v ...any) {
 	tl.append(fmt.Sprintf(format, v...))
 }
+
+// Warn implements model.Logger
 func (tl *TestLogger) Warn(msg string) {
 	tl.append(msg)
 }
+
+// Warnf implements model.Logger
 func (tl *TestLogger) Warnf(format string, v ...any) {
 	tl.append(fmt.Sprintf(format, v...))
 }
 
 func NewTestLogger() *TestLogger {
 	return &TestLogger{
 		Lines: make([]string, 0),
 	}

internal/session/manager.go

@@ -40,6 +40,9 @@ type Manager struct {
 	// Ready is a channel where we signal that we can start accepting data, because we've
 	// successfully generated key material for the data channel.
 	Ready chan any
+
+	// Failure is a channel where we receive any unrecoverable error.
+	Failure chan error
 }
 
 // NewManager returns a [Manager] ready to be used.
@@ -62,7 +65,8 @@ func NewManager(config *config.Config) (*Manager, error) {
 		// the data packet ID counter to zero.
 		localDataPacketID: 1,
 
-		Ready: make(chan any),
+		Ready:   make(chan any),
+		Failure: make(chan error),
 	}
 
 	randomBytes, err := randomFn(8)
@@ -111,7 +115,7 @@ func (m *Manager) IsRemoteSessionIDSet() bool {
 	return !m.remoteSessionID.IsNone()
 }
 
-// NewACKForPacket creates a new ACK for the given packet IDs.
+// NewACKForPacketIDs creates a new ACK for the given packet IDs.
 func (m *Manager) NewACKForPacketIDs(ids []model.PacketID) (*model.Packet, error) {
 	defer m.mu.Unlock()
 	m.mu.Lock()
@@ -144,9 +148,8 @@ func (m *Manager) NewPacket(opcode model.Opcode, payload []byte) (*model.Packet,
 	pid, err := func() (model.PacketID, error) {
 		if opcode.IsControl() {
 			return m.localControlPacketIDLocked()
-		} else {
-			return m.localDataPacketIDLocked()
 		}
+		return m.localDataPacketIDLocked()
 	}()
 	if err != nil {
 		return nil, err
@@ -245,6 +248,7 @@ func (m *Manager) SetRemoteSessionID(remoteSessionID model.SessionID) {
 	m.remoteSessionID = optional.Some(remoteSessionID)
 }
 
+// CurrentKeyID returns the key ID currently in use.
 func (m *Manager) CurrentKeyID() uint8 {
 	defer m.mu.Unlock()
 	m.mu.Lock()

internal/tlssession/tlshandshake.go

@@ -122,6 +122,7 @@ type certConfig struct {
 func newCertConfigFromOptions(o *config.OpenVPNOptions) (*certConfig, error) {
 	var cfg *certConfig
 	var err error
+
 	if o.ShouldLoadCertsFromPath() {
 		cfg, err = loadCertAndCAFromPath(certPaths{
 			certPath: o.CertPath,

internal/tlssession/tlssession.go

@@ -1,6 +1,7 @@
 package tlssession
 
 import (
+	"errors"
 	"fmt"
 	"net"
 
@@ -88,8 +89,17 @@ func (ws *workersState) worker() {
 		case notif := <-ws.notifyTLS:
 			if (notif.Flags & model.NotificationReset) != 0 {
 				if err := ws.tlsAuth(); err != nil {
+
+					// TODO(ainghazal): pass the failure to the tracer too.
+
+					if errors.Is(err, ErrBadCA) {
+						ws.sessionManager.Failure <- err
+						return
+					}
+					// The following errors are not handled, will just appear
+					// as warnings in the log. We should catch any errors that we want to
+					// deal with as unrecoverable failures in the block above.
 					ws.logger.Warnf("%s: %s", workerName, err.Error())
-					// TODO: is it worth checking the return value and stopping?
 				}
 			}
 

internal/tun/tun.go

@@ -4,6 +4,7 @@ import (
 	"bytes"
 	"context"
 	"errors"
+	"fmt"
 	"net"
 	"os"
 	"sync"
@@ -18,6 +19,9 @@ import (
 var (
 	// default TLS handshake timeout, in seconds.
 	tlsHandshakeTimeoutSeconds = 60
+
+	// ErrCannotHandshake is the generic error we return when we cannot complete a handshake.
+	ErrCannotHandshake = errors.New("openvpn handshake error")
 )
 
 // StartTUN initializes and starts the TUN device over the vpn.
@@ -49,17 +53,27 @@ func StartTUN(ctx context.Context, conn networkio.FramingConn, config *config.Co
 	select {
 	case <-sessionManager.Ready:
 		return tunnel, nil
+	case failure := <-sessionManager.Failure:
+		err := fmt.Errorf("%w: %s", ErrCannotHandshake, failure)
+		defer func() {
+			config.Logger().Warn(err.Error())
+			tunnel.Close()
+		}()
+		return nil, err
 	case <-tlsTimeout.C:
+		err := fmt.Errorf("%w: %s", ErrCannotHandshake, "tls timeout")
 		defer func() {
-			config.Logger().Info("tls timeout")
+			config.Logger().Warn(err.Error())
 			tunnel.Close()
 		}()
-		return nil, errors.New("tls timeout")
+		return nil, err
 	case <-ctx.Done():
+		err := fmt.Errorf("%w: %w", ErrCannotHandshake, ctx.Err())
 		defer func() {
+			config.Logger().Warn(err.Error())
 			tunnel.Close()
 		}()
-		return nil, ctx.Err()
+		return nil, err
 	}
 }
 

pkg/tracex/trace.go

@@ -56,17 +56,21 @@ type Event struct {
 
 	// LoggedPacket is an optional packet metadata.
 	LoggedPacket optional.Value[LoggedPacket] `json:"packet"`
+
+	// TransactionID is an optional index identifying one particular handshake.
+	TransactionID int64 `json:"transaction_id,omitempty"`
 }
 
 type NegotiationState = model.NegotiationState
 
-func newEvent(etype HandshakeEventType, st NegotiationState, t time.Time, t0 time.Time) *Event {
+func newEvent(etype HandshakeEventType, st NegotiationState, t time.Time, t0 time.Time, txid int64) *Event {
 	return &Event{
-		EventType:    etype.String(),
-		Stage:        st.String()[2:],
-		AtTime:       t.Sub(t0).Seconds(),
-		Tags:         make([]string, 0),
-		LoggedPacket: optional.None[LoggedPacket](),
+		EventType:     etype.String(),
+		Stage:         st.String()[2:],
+		AtTime:        t.Sub(t0).Seconds(),
+		Tags:          make([]string, 0),
+		LoggedPacket:  optional.None[LoggedPacket](),
+		TransactionID: txid,
 	}
 }
 
@@ -78,6 +82,9 @@ type Tracer struct {
 	// mu guards access to the events.
 	mu sync.Mutex
 
+	// transactionID is an optional index that will be added to any events produced by this tracer.
+	transactionID int64
+
 	// zeroTime is the time when we started a packet trace.
 	zeroTime time.Time
 }
@@ -89,6 +96,17 @@ func NewTracer(start time.Time) *Tracer {
 	}
 }
 
+// NewTracerWithTransactionID returns a Tracer with the passed start time and the given
+// identifier for a transaction. Transaction IDs are meant as a convenience to use
+// this tracer out-of-the-box from within the ooni probes, and it follows the expected
+// semantics to cross-reference measurements.
+func NewTracerWithTransactionID(start time.Time, txid int64) *Tracer {
+	return &Tracer{
+		transactionID: txid,
+		zeroTime:      start,
+	}
+}
+
 // TimeNow allows to manipulate time for deterministic tests.
 func (t *Tracer) TimeNow() time.Time {
 	return time.Now()
@@ -99,7 +117,7 @@ func (t *Tracer) OnStateChange(state NegotiationState) {
 	t.mu.Lock()
 	defer t.mu.Unlock()
 
-	e := newEvent(handshakeEventStateChange, state, t.TimeNow(), t.zeroTime)
+	e := newEvent(handshakeEventStateChange, state, t.TimeNow(), t.zeroTime, t.transactionID)
 	t.events = append(t.events, e)
 }
 
@@ -108,7 +126,7 @@ func (t *Tracer) OnIncomingPacket(packet *model.Packet, stage NegotiationState)
 	t.mu.Lock()
 	defer t.mu.Unlock()
 
-	e := newEvent(handshakeEventPacketIn, stage, t.TimeNow(), t.zeroTime)
+	e := newEvent(handshakeEventPacketIn, stage, t.TimeNow(), t.zeroTime, t.transactionID)
 	e.LoggedPacket = logPacket(packet, optional.None[int](), model.DirectionIncoming)
 	maybeAddTagsFromPacket(e, packet)
 	t.events = append(t.events, e)
@@ -119,7 +137,7 @@ func (t *Tracer) OnOutgoingPacket(packet *model.Packet, stage NegotiationState,
 	t.mu.Lock()
 	defer t.mu.Unlock()
 
-	e := newEvent(handshakeEventPacketOut, stage, t.TimeNow(), t.zeroTime)
+	e := newEvent(handshakeEventPacketOut, stage, t.TimeNow(), t.zeroTime, t.transactionID)
 	e.LoggedPacket = logPacket(packet, optional.Some(retries), model.DirectionOutgoing)
 	maybeAddTagsFromPacket(e, packet)
 	t.events = append(t.events, e)
@@ -130,7 +148,7 @@ func (t *Tracer) OnDroppedPacket(direction model.Direction, stage NegotiationSta
 	t.mu.Lock()
 	defer t.mu.Unlock()
 
-	e := newEvent(handshakeEventPacketDropped, stage, t.TimeNow(), t.zeroTime)
+	e := newEvent(handshakeEventPacketDropped, stage, t.TimeNow(), t.zeroTime, t.transactionID)
 	e.LoggedPacket = logPacket(packet, optional.None[int](), direction)
 	t.events = append(t.events, e)
 }

pkg/tunnel/tunnel.go

@@ -5,11 +5,10 @@ import (
 	"context"
 	"net"
 
+	"github.com/apex/log"
 	"github.com/ooni/minivpn/internal/networkio"
 	"github.com/ooni/minivpn/internal/tun"
 	"github.com/ooni/minivpn/pkg/config"
-
-	"github.com/apex/log"
 )
 
 // SimpleDialer establishes network connections.