From 69602abe8a01bfab5591d6f562324fe164182c87 Mon Sep 17 00:00:00 2001 From: DecFox <33030671+DecFox@users.noreply.github.com> Date: Wed, 17 Aug 2022 12:49:11 +0530 Subject: [PATCH] refactor(simplequicping): use step-by-step (#852) See https://github.com/ooni/probe/issues/2159 and https://github.com/ooni/spec/pull/254 --- .../simplequicping/simplequicping.go | 60 ++-- .../simplequicping/simplequicping_test.go | 2 +- internal/measurexlite/conn.go | 61 ++++ internal/measurexlite/conn_test.go | 168 ++++++++++ internal/measurexlite/quic.go | 116 +++++++ internal/measurexlite/quic_test.go | 315 ++++++++++++++++++ internal/measurexlite/tls.go | 4 +- internal/measurexlite/tls_test.go | 2 + internal/measurexlite/trace.go | 25 ++ internal/measurexlite/trace_test.go | 94 ++++++ internal/model/archival.go | 1 + internal/model/mocks/trace.go | 15 + internal/model/mocks/trace_test.go | 34 ++ internal/model/netx.go | 35 ++ internal/netxlite/quic.go | 6 + internal/netxlite/trace.go | 10 + 16 files changed, 922 insertions(+), 26 deletions(-) create mode 100644 internal/measurexlite/quic.go create mode 100644 internal/measurexlite/quic_test.go diff --git a/internal/engine/experiment/simplequicping/simplequicping.go b/internal/engine/experiment/simplequicping/simplequicping.go index 6114db1..51edba7 100644 --- a/internal/engine/experiment/simplequicping/simplequicping.go +++ b/internal/engine/experiment/simplequicping/simplequicping.go @@ -13,14 +13,15 @@ import ( "strings" "time" - "github.com/ooni/probe-cli/v3/internal/measurex" + "github.com/lucas-clemente/quic-go" + "github.com/ooni/probe-cli/v3/internal/measurexlite" "github.com/ooni/probe-cli/v3/internal/model" "github.com/ooni/probe-cli/v3/internal/netxlite" ) const ( testName = "simplequicping" - testVersion = "0.1.0" + testVersion = "0.2.0" ) // Config contains the experiment configuration. @@ -77,8 +78,8 @@ type TestKeys struct { // SinglePing contains the results of a single ping. type SinglePing struct { - NetworkEvents []*measurex.ArchivalNetworkEvent `json:"network_events"` - QUICHandshakes []*measurex.ArchivalQUICTLSHandshakeEvent `json:"quic_handshakes"` + NetworkEvents []*model.ArchivalNetworkEvent `json:"network_events"` + QUICHandshake *model.ArchivalTLSOrQUICHandshakeResult `json:"quic_handshake"` } // Measurer performs the measurement. @@ -132,47 +133,58 @@ func (m *Measurer) Run( } tk := new(TestKeys) measurement.TestKeys = tk - out := make(chan *measurex.EndpointMeasurement) - mxmx := measurex.NewMeasurerWithDefaultSettings() - go m.simpleQUICPingLoop(ctx, mxmx, parsed.Host, out) + out := make(chan *SinglePing) + go m.simpleQUICPingLoop(ctx, measurement.MeasurementStartTimeSaved, sess.Logger(), parsed.Host, out) for len(tk.Pings) < int(m.config.repetitions()) { - meas := <-out - tk.Pings = append(tk.Pings, &SinglePing{ - NetworkEvents: measurex.NewArchivalNetworkEventList(meas.ReadWrite), - QUICHandshakes: measurex.NewArchivalQUICTLSHandshakeEventList(meas.QUICHandshake), - }) + tk.Pings = append(tk.Pings, <-out) } return nil // return nil so we always submit the measurement } // simpleQUICPingLoop sends all the ping requests and emits the results onto the out channel. -func (m *Measurer) simpleQUICPingLoop(ctx context.Context, mxmx *measurex.Measurer, - address string, out chan<- *measurex.EndpointMeasurement) { +func (m *Measurer) simpleQUICPingLoop(ctx context.Context, zeroTime time.Time, + logger model.Logger, address string, out chan<- *SinglePing) { ticker := time.NewTicker(m.config.delay()) defer ticker.Stop() for i := int64(0); i < m.config.repetitions(); i++ { - go m.simpleQUICPingAsync(ctx, mxmx, address, out) + go m.simpleQUICPingAsync(ctx, i, zeroTime, logger, address, out) <-ticker.C } } // simpleQUICPingAsync performs a QUIC ping and emits the result onto the out channel. -func (m *Measurer) simpleQUICPingAsync(ctx context.Context, mxmx *measurex.Measurer, - address string, out chan<- *measurex.EndpointMeasurement) { - out <- m.quicHandshake(ctx, mxmx, address) +func (m *Measurer) simpleQUICPingAsync(ctx context.Context, index int64, + zeroTime time.Time, logger model.Logger, address string, out chan<- *SinglePing) { + out <- m.quicHandshake(ctx, index, zeroTime, logger, address) } // quicHandshake performs a QUIC handshake and returns the results of these operations to the caller. -func (m *Measurer) quicHandshake(ctx context.Context, mxmx *measurex.Measurer, - address string) *measurex.EndpointMeasurement { +func (m *Measurer) quicHandshake(ctx context.Context, index int64, + zeroTime time.Time, logger model.Logger, address string) *SinglePing { // TODO(bassosimone): make the timeout user-configurable ctx, cancel := context.WithTimeout(ctx, 3*time.Second) defer cancel() - return mxmx.QUICHandshake(ctx, address, &tls.Config{ - NextProtos: strings.Split(m.config.alpn(), " "), + sp := &SinglePing{ + NetworkEvents: []*model.ArchivalNetworkEvent{}, + QUICHandshake: nil, + } + sni := m.config.sni(address) + alpn := strings.Split(m.config.alpn(), " ") + trace := measurexlite.NewTrace(index, zeroTime) + ol := measurexlite.NewOperationLogger(logger, "SimpleQUICPing #%d %s %s %v", index, address, sni, alpn) + quicListener := netxlite.NewQUICListener() + listener := trace.WrapQUICListener(quicListener) + dialer := trace.NewQUICDialerWithoutResolver(listener, logger) + tlsConfig := &tls.Config{ + NextProtos: alpn, RootCAs: netxlite.NewDefaultCertPool(), - ServerName: m.config.sni(address), - }) + ServerName: sni, + } + _, err := dialer.DialContext(ctx, "udp", address, tlsConfig, &quic.Config{}) + ol.Stop(err) + sp.QUICHandshake = <-trace.QUICHandshake + sp.NetworkEvents = append(sp.NetworkEvents, trace.NetworkEvents()...) + return sp } // NewExperimentMeasurer creates a new ExperimentMeasurer. diff --git a/internal/engine/experiment/simplequicping/simplequicping_test.go b/internal/engine/experiment/simplequicping/simplequicping_test.go index 58addd4..cdd4138 100644 --- a/internal/engine/experiment/simplequicping/simplequicping_test.go +++ b/internal/engine/experiment/simplequicping/simplequicping_test.go @@ -54,7 +54,7 @@ func TestMeasurer_run(t *testing.T) { if m.ExperimentName() != "simplequicping" { t.Fatal("invalid experiment name") } - if m.ExperimentVersion() != "0.1.0" { + if m.ExperimentVersion() != "0.2.0" { t.Fatal("invalid experiment version") } ctx := context.Background() diff --git a/internal/measurexlite/conn.go b/internal/measurexlite/conn.go index a688bd4..b7379fb 100644 --- a/internal/measurexlite/conn.go +++ b/internal/measurexlite/conn.go @@ -69,6 +69,67 @@ func (c *connTrace) Write(b []byte) (int, error) { return count, err } +// MaybeUDPLikeClose is a convenience function for closing a conn only when such a conn isn't nil. +func MaybeCloseUDPLikeConn(conn model.UDPLikeConn) (err error) { + if conn != nil { + err = conn.Close() + } + return +} + +// WrapUDPLikeConn returns a wrapped conn that saves network events into this trace. +func (tx *Trace) WrapUDPLikeConn(conn model.UDPLikeConn) model.UDPLikeConn { + return &udpLikeConnTrace{ + UDPLikeConn: conn, + tx: tx, + } +} + +// udpLikeConnTrace is a trace-aware model.UDPLikeConn. +type udpLikeConnTrace struct { + // Implementation note: it seems ~safe to use embedding here because model.UDPLikeConn + // contains fields deriving from how lucas-clemente/quic-go uses the standard library + model.UDPLikeConn + tx *Trace +} + +// Read implements model.UDPLikeConn.ReadFrom and saves network events. +func (c *udpLikeConnTrace) ReadFrom(b []byte) (int, net.Addr, error) { + started := c.tx.TimeSince(c.tx.ZeroTime) + count, addr, err := c.UDPLikeConn.ReadFrom(b) + finished := c.tx.TimeSince(c.tx.ZeroTime) + address := addrStringIfNotNil(addr) + select { + case c.tx.NetworkEvent <- NewArchivalNetworkEvent( + c.tx.Index, started, netxlite.ReadFromOperation, "udp", address, count, err, finished): + default: // buffer is full + } + return count, addr, err +} + +// Write implements model.UDPLikeConn.WriteTo and saves network events. +func (c *udpLikeConnTrace) WriteTo(b []byte, addr net.Addr) (int, error) { + started := c.tx.TimeSince(c.tx.ZeroTime) + address := addr.String() + count, err := c.UDPLikeConn.WriteTo(b, addr) + finished := c.tx.TimeSince(c.tx.ZeroTime) + select { + case c.tx.NetworkEvent <- NewArchivalNetworkEvent( + c.tx.Index, started, netxlite.WriteToOperation, "udp", address, count, err, finished): + default: // buffer is full + } + return count, err +} + +// addrStringIfNotNil returns the string of the given addr +// unless the addr is nil, in which case it returns an empty string. +func addrStringIfNotNil(addr net.Addr) (out string) { + if addr != nil { + out = addr.String() + } + return +} + // NewArchivalNetworkEvent creates a new model.ArchivalNetworkEvent. func NewArchivalNetworkEvent(index int64, started time.Duration, operation string, network string, address string, count int, err error, finished time.Duration) *model.ArchivalNetworkEvent { diff --git a/internal/measurexlite/conn_test.go b/internal/measurexlite/conn_test.go index 792a374..a24f38e 100644 --- a/internal/measurexlite/conn_test.go +++ b/internal/measurexlite/conn_test.go @@ -219,6 +219,174 @@ func TestWrapNetConn(t *testing.T) { }) } +func TestWrapUDPLikeConn(t *testing.T) { + t.Run("WrapUDPLikeConn wraps the conn", func(t *testing.T) { + underlying := &mocks.UDPLikeConn{} + zeroTime := time.Now() + trace := NewTrace(0, zeroTime) + conn := trace.WrapUDPLikeConn(underlying) + ct := conn.(*udpLikeConnTrace) + if ct.UDPLikeConn != underlying { + t.Fatal("invalid underlying") + } + if ct.tx != trace { + t.Fatal("invalid trace") + } + }) + + t.Run("ReadFrom saves a trace", func(t *testing.T) { + underlying := &mocks.UDPLikeConn{ + MockReadFrom: func(b []byte) (int, net.Addr, error) { + return len(b), &mocks.Addr{ + MockString: func() string { + return "1.1.1.1:443" + }, + }, nil + }, + } + zeroTime := time.Now() + td := testingx.NewTimeDeterministic(zeroTime) + trace := NewTrace(0, zeroTime) + trace.TimeNowFn = td.Now // deterministic time counting + conn := trace.WrapUDPLikeConn(underlying) + const bufsiz = 128 + buffer := make([]byte, bufsiz) + count, addr, err := conn.ReadFrom(buffer) + if count != bufsiz { + t.Fatal("invalid count") + } + if addr.String() != "1.1.1.1:443" { + t.Fatal("invalid address") + } + if err != nil { + t.Fatal("invalid err") + } + events := trace.NetworkEvents() + if len(events) != 1 { + t.Fatal("did not save network events") + } + expect := &model.ArchivalNetworkEvent{ + Address: "1.1.1.1:443", + Failure: nil, + NumBytes: bufsiz, + Operation: "read_from", + Proto: "udp", + T: 1.0, + Tags: []string{}, + } + got := events[0] + if diff := cmp.Diff(expect, got); diff != "" { + t.Fatal(diff) + } + }) + + t.Run("ReadFrom discards the event when the buffer is full", func(t *testing.T) { + underlying := &mocks.UDPLikeConn{ + MockReadFrom: func(b []byte) (int, net.Addr, error) { + return len(b), &mocks.Addr{ + MockString: func() string { + return "1.1.1.1:443" + }, + }, nil + }, + } + zeroTime := time.Now() + trace := NewTrace(0, zeroTime) + trace.NetworkEvent = make(chan *model.ArchivalNetworkEvent) // no buffer + conn := trace.WrapUDPLikeConn(underlying) + const bufsiz = 128 + buffer := make([]byte, bufsiz) + count, addr, err := conn.ReadFrom(buffer) + if count != bufsiz { + t.Fatal("invalid count") + } + if addr.String() != "1.1.1.1:443" { + t.Fatal("invalid address") + } + if err != nil { + t.Fatal("invalid err") + } + events := trace.NetworkEvents() + if len(events) != 0 { + t.Fatal("expected no network events") + } + }) + + t.Run("WriteTo saves a trace", func(t *testing.T) { + underlying := &mocks.UDPLikeConn{ + MockWriteTo: func(b []byte, addr net.Addr) (int, error) { + return len(b), nil + }, + } + zeroTime := time.Now() + td := testingx.NewTimeDeterministic(zeroTime) + trace := NewTrace(0, zeroTime) + trace.TimeNowFn = td.Now // deterministic time tracking + conn := trace.WrapUDPLikeConn(underlying) + const bufsiz = 128 + buffer := make([]byte, bufsiz) + addr := &mocks.Addr{ + MockString: func() string { + return "1.1.1.1:443" + }, + } + count, err := conn.WriteTo(buffer, addr) + if count != bufsiz { + t.Fatal("invalid count") + } + if err != nil { + t.Fatal("invalid err") + } + events := trace.NetworkEvents() + if len(events) != 1 { + t.Fatal("did not save network events") + } + expect := &model.ArchivalNetworkEvent{ + Address: "1.1.1.1:443", + Failure: nil, + NumBytes: bufsiz, + Operation: "write_to", + Proto: "udp", + T: 1.0, + Tags: []string{}, + } + got := events[0] + if diff := cmp.Diff(expect, got); diff != "" { + t.Fatal(diff) + } + }) + + t.Run("Write discards the event when the buffer is full", func(t *testing.T) { + underlying := &mocks.UDPLikeConn{ + MockWriteTo: func(b []byte, addr net.Addr) (int, error) { + return len(b), nil + }, + } + zeroTime := time.Now() + trace := NewTrace(0, zeroTime) + trace.NetworkEvent = make(chan *model.ArchivalNetworkEvent) // no buffer + conn := trace.WrapUDPLikeConn(underlying) + const bufsiz = 128 + buffer := make([]byte, bufsiz) + addr := &mocks.Addr{ + MockString: func() string { + return "1.1.1.1:443" + }, + } + count, err := conn.WriteTo(buffer, addr) + if count != bufsiz { + t.Fatal("invalid count") + } + if err != nil { + t.Fatal("invalid err") + } + events := trace.NetworkEvents() + if len(events) != 0 { + t.Fatal("expected no network events") + } + }) +} + func TestNewAnnotationArchivalNetworkEvent(t *testing.T) { var ( index int64 = 3 diff --git a/internal/measurexlite/quic.go b/internal/measurexlite/quic.go new file mode 100644 index 0000000..0ecd105 --- /dev/null +++ b/internal/measurexlite/quic.go @@ -0,0 +1,116 @@ +package measurexlite + +// +// QUIC tracing +// + +import ( + "context" + "crypto/tls" + "net" + "time" + + "github.com/lucas-clemente/quic-go" + "github.com/ooni/probe-cli/v3/internal/model" + "github.com/ooni/probe-cli/v3/internal/netxlite" +) + +// WrapQUICListener returns a wrapped model.QUICListener that uses this trace. +func (tx *Trace) WrapQUICListener(listener model.QUICListener) model.QUICListener { + return &quicListenerTrace{ + QUICListener: listener, + tx: tx, + } +} + +// quicListenerTrace is a trace-aware QUIC listener. +type quicListenerTrace struct { + model.QUICListener + tx *Trace +} + +// Listen implements model.QUICListener.Listen +func (ql *quicListenerTrace) Listen(addr *net.UDPAddr) (model.UDPLikeConn, error) { + pconn, err := ql.QUICListener.Listen(addr) + if err != nil { + return nil, err + } + return ql.tx.WrapUDPLikeConn(pconn), nil +} + +// NewQUICDialerWithoutResolver is equivalent to netxlite.NewQUICDialerWithoutResolver +// except that it returns a model.QUICDialer that uses this trace. +func (tx *Trace) NewQUICDialerWithoutResolver(listener model.QUICListener, dl model.DebugLogger) model.QUICDialer { + return &quicDialerTrace{ + qd: tx.newQUICDialerWithoutResolver(listener, dl), + tx: tx, + } +} + +// quicDialerTrace is a trace-aware QUIC dialer. +type quicDialerTrace struct { + qd model.QUICDialer + tx *Trace +} + +var _ model.QUICDialer = &quicDialerTrace{} + +// DialContext implements model.QUICDialer.DialContext. +func (qdx *quicDialerTrace) DialContext(ctx context.Context, network string, + address string, tlsConfig *tls.Config, quicConfig *quic.Config) ( + quic.EarlyConnection, error) { + return qdx.qd.DialContext(netxlite.ContextWithTrace(ctx, qdx.tx), network, address, tlsConfig, quicConfig) +} + +// CloseIdleConnections implements model.QUICDialer.CloseIdleConnections. +func (qdx *quicDialerTrace) CloseIdleConnections() { + qdx.qd.CloseIdleConnections() +} + +// OnQUICHandshakeStart implements model.Trace.OnQUICHandshakeStart +func (tx *Trace) OnQUICHandshakeStart(now time.Time, remoteAddr string, config *quic.Config) { + t := now.Sub(tx.ZeroTime) + select { + case tx.NetworkEvent <- NewAnnotationArchivalNetworkEvent(tx.Index, t, "quic_handshake_start"): + default: + } +} + +// OnQUICHandshakeDone implements model.Trace.OnQUICHandshakeDone +func (tx *Trace) OnQUICHandshakeDone(started time.Time, remoteAddr string, qconn quic.EarlyConnection, + config *tls.Config, err error, finished time.Time) { + t := finished.Sub(tx.ZeroTime) + state := tls.ConnectionState{} + if qconn != nil { + state = qconn.ConnectionState().TLS.ConnectionState + } + select { + case tx.QUICHandshake <- NewArchivalTLSOrQUICHandshakeResult( + tx.Index, + started.Sub(tx.ZeroTime), + "quic", + remoteAddr, + config, + state, + err, + t, + ): + default: // buffer is full + } + select { + case tx.NetworkEvent <- NewAnnotationArchivalNetworkEvent(tx.Index, t, "quic_handshake_done"): + default: // buffer is full + } +} + +// QUICHandshakes drains the network events buffered inside the QUICHandshake channel. +func (tx *Trace) QUICHandshakes() (out []*model.ArchivalTLSOrQUICHandshakeResult) { + for { + select { + case ev := <-tx.QUICHandshake: + out = append(out, ev) + default: + return // done + } + } +} diff --git a/internal/measurexlite/quic_test.go b/internal/measurexlite/quic_test.go new file mode 100644 index 0000000..b105688 --- /dev/null +++ b/internal/measurexlite/quic_test.go @@ -0,0 +1,315 @@ +package measurexlite + +import ( + "context" + "crypto/tls" + "errors" + "net" + "syscall" + "testing" + "time" + + "github.com/google/go-cmp/cmp" + "github.com/lucas-clemente/quic-go" + "github.com/ooni/probe-cli/v3/internal/model" + "github.com/ooni/probe-cli/v3/internal/model/mocks" + "github.com/ooni/probe-cli/v3/internal/netxlite" + "github.com/ooni/probe-cli/v3/internal/testingx" +) + +func TestNewQUICListener(t *testing.T) { + t.Run("NewQUICListenerTrace creates a wrapped listener", func(t *testing.T) { + underlying := &mocks.QUICListener{} + zeroTime := time.Now() + trace := NewTrace(0, zeroTime) + listenert := trace.WrapQUICListener(underlying).(*quicListenerTrace) + if listenert.QUICListener != underlying { + t.Fatal("invalid quic dialer") + } + if listenert.tx != trace { + t.Fatal("invalid trace") + } + }) + + t.Run("Listen works as intended", func(t *testing.T) { + t.Run("with error", func(t *testing.T) { + zeroTime := time.Now() + trace := NewTrace(0, zeroTime) + mockedErr := errors.New("mocked") + mockListener := &mocks.QUICListener{ + MockListen: func(addr *net.UDPAddr) (model.UDPLikeConn, error) { + return nil, mockedErr + }, + } + listener := trace.WrapQUICListener(mockListener) + pconn, err := listener.Listen(&net.UDPAddr{}) + if !errors.Is(err, mockedErr) { + t.Fatal("unexpected err", err) + } + if pconn != nil { + t.Fatal("expected nil conn") + } + }) + + t.Run("without error", func(t *testing.T) { + zeroTime := time.Now() + trace := NewTrace(0, zeroTime) + mockConn := &mocks.UDPLikeConn{} + mockListener := &mocks.QUICListener{ + MockListen: func(addr *net.UDPAddr) (model.UDPLikeConn, error) { + return mockConn, nil + }, + } + listener := trace.WrapQUICListener(mockListener) + pconn, err := listener.Listen(&net.UDPAddr{}) + if err != nil { + t.Fatal("unexpected err", err) + } + conn := pconn.(*udpLikeConnTrace) + if conn.UDPLikeConn != mockConn { + t.Fatal("invalid conn") + } + if conn.tx != trace { + t.Fatal("invalid trace") + } + }) + }) +} + +func TestNewQUICDialerWithoutResolver(t *testing.T) { + t.Run("NewQUICDialerWithoutResolver creates a wrapped dialer", func(t *testing.T) { + underlying := &mocks.QUICDialer{} + zeroTime := time.Now() + trace := NewTrace(0, zeroTime) + trace.NewQUICDialerWithoutResolverFn = func(listener model.QUICListener, dl model.DebugLogger) model.QUICDialer { + return underlying + } + listener := &mocks.QUICListener{} + dialer := trace.NewQUICDialerWithoutResolver(listener, model.DiscardLogger) + dt := dialer.(*quicDialerTrace) + if dt.qd != underlying { + t.Fatal("invalid quic dialer") + } + if dt.tx != trace { + t.Fatal("invalid trace") + } + }) + + t.Run("DialContext calls the underlying dialer with context-based tracing", func(t *testing.T) { + expectedErr := errors.New("mocked err") + zeroTime := time.Now() + trace := NewTrace(0, zeroTime) + var hasCorrectTrace bool + underlying := &mocks.QUICDialer{ + MockDialContext: func(ctx context.Context, network, address string, tlsConfig *tls.Config, + quicConfig *quic.Config) (quic.EarlyConnection, error) { + gotTrace := netxlite.ContextTraceOrDefault(ctx) + hasCorrectTrace = (gotTrace == trace) + return nil, expectedErr + }, + } + trace.NewQUICDialerWithoutResolverFn = func(listener model.QUICListener, dl model.DebugLogger) model.QUICDialer { + return underlying + } + listener := &mocks.QUICListener{} + dialer := trace.NewQUICDialerWithoutResolver(listener, model.DiscardLogger) + ctx := context.Background() + conn, err := dialer.DialContext(ctx, "udp", "1.1.1.1:443", &tls.Config{}, &quic.Config{}) + if !errors.Is(err, expectedErr) { + t.Fatal("unexpected err", err) + } + if conn != nil { + t.Fatal("expected nil conn") + } + if !hasCorrectTrace { + t.Fatal("does not have the correct trace") + } + }) + + t.Run("CloseIdleConnection is correctly forwarded", func(t *testing.T) { + var called bool + zeroTime := time.Now() + trace := NewTrace(0, zeroTime) + underlying := &mocks.QUICDialer{ + MockCloseIdleConnections: func() { + called = true + }, + } + trace.NewQUICDialerWithoutResolverFn = func(listener model.QUICListener, dl model.DebugLogger) model.QUICDialer { + return underlying + } + listener := &mocks.QUICListener{} + dialer := trace.NewQUICDialerWithoutResolver(listener, model.DiscardLogger) + dialer.CloseIdleConnections() + if !called { + t.Fatal("not called") + } + }) + + t.Run("DialContext saves into trace", func(t *testing.T) { + mockedErr := errors.New("mocked") + zeroTime := time.Now() + td := testingx.NewTimeDeterministic(zeroTime) + trace := NewTrace(0, zeroTime) + trace.TimeNowFn = td.Now // deterministic time tracking + pconn := &mocks.UDPLikeConn{ + MockLocalAddr: func() net.Addr { + return &net.UDPAddr{ + Port: 0, + } + }, + MockRemoteAddr: func() net.Addr { + return &net.UDPAddr{ + Port: 0, + } + }, + MockSyscallConn: func() (syscall.RawConn, error) { + return nil, mockedErr + }, + MockClose: func() error { + return nil + }, + } + listener := &mocks.QUICListener{ + MockListen: func(addr *net.UDPAddr) (model.UDPLikeConn, error) { + return pconn, nil + }, + } + dialer := trace.NewQUICDialerWithoutResolver(listener, model.DiscardLogger) + tlsConfig := &tls.Config{ + InsecureSkipVerify: true, + ServerName: "dns.cloudflare.com", + } + ctx := context.Background() + qconn, err := dialer.DialContext(ctx, "udp", "1.1.1.1:443", tlsConfig, &quic.Config{}) + if !errors.Is(err, mockedErr) { + t.Fatal("unexpected err", err) + } + if qconn != nil { + t.Fatal("expected nil qconn") + } + + t.Run("QUICHandshake events", func(t *testing.T) { + events := trace.QUICHandshakes() + if len(events) != 1 { + t.Fatal("expected to see single QUICHandshake event") + } + expectedFailure := "unknown_failure: mocked" + expect := &model.ArchivalTLSOrQUICHandshakeResult{ + Network: "quic", + Address: "1.1.1.1:443", + CipherSuite: "", + Failure: &expectedFailure, + NegotiatedProtocol: "", + NoTLSVerify: true, + PeerCertificates: []model.ArchivalMaybeBinaryData{}, + ServerName: "dns.cloudflare.com", + T: time.Second.Seconds(), + Tags: []string{}, + TLSVersion: "", + } + got := events[0] + if diff := cmp.Diff(expect, got); diff != "" { + t.Fatal(diff) + } + }) + + t.Run("Network events", func(t *testing.T) { + events := trace.NetworkEvents() + if len(events) != 2 { + t.Fatal("expected to see three Network events") + } + + t.Run("quic_handshake_start", func(t *testing.T) { + expect := &model.ArchivalNetworkEvent{ + Address: "", + Failure: nil, + NumBytes: 0, + Operation: "quic_handshake_start", + Proto: "", + T: 0, + Tags: []string{}, + } + got := events[0] + if diff := cmp.Diff(expect, got); diff != "" { + t.Fatal(diff) + } + }) + + t.Run("quic_handshake_done", func(t *testing.T) { + expect := &model.ArchivalNetworkEvent{ + Address: "", + Failure: nil, + NumBytes: 0, + Operation: "quic_handshake_done", + Proto: "", + T: time.Second.Seconds(), + Tags: []string{}, + } + got := events[1] + if diff := cmp.Diff(expect, got); diff != "" { + t.Fatal(diff) + } + }) + }) + + }) + + t.Run("DialContext discards events when buffer is full", func(t *testing.T) { + mockedErr := errors.New("mocked") + zeroTime := time.Now() + trace := NewTrace(0, zeroTime) + trace.NetworkEvent = make(chan *model.ArchivalNetworkEvent) // no buffer + trace.QUICHandshake = make(chan *model.ArchivalTLSOrQUICHandshakeResult) // no buffer + pconn := &mocks.UDPLikeConn{ + MockLocalAddr: func() net.Addr { + return &net.UDPAddr{ + Port: 0, + } + }, + MockRemoteAddr: func() net.Addr { + return &net.UDPAddr{ + Port: 0, + } + }, + MockSyscallConn: func() (syscall.RawConn, error) { + return nil, mockedErr + }, + MockClose: func() error { + return nil + }, + } + listener := &mocks.QUICListener{ + MockListen: func(addr *net.UDPAddr) (model.UDPLikeConn, error) { + return pconn, nil + }, + } + dialer := trace.NewQUICDialerWithoutResolver(listener, model.DiscardLogger) + tlsConfig := &tls.Config{ + InsecureSkipVerify: true, + ServerName: "dns.cloudflare.com", + } + ctx := context.Background() + qconn, err := dialer.DialContext(ctx, "udp", "1.1.1.1:443", tlsConfig, &quic.Config{}) + if !errors.Is(err, mockedErr) { + t.Fatal("unexpected err", err) + } + if qconn != nil { + t.Fatal("expected nil qconn") + } + + t.Run("QUiCHandshake events", func(t *testing.T) { + events := trace.QUICHandshakes() + if len(events) != 0 { + t.Fatal("expected to see no QUICHandshake events") + } + }) + + t.Run("Network events", func(t *testing.T) { + events := trace.NetworkEvents() + if len(events) != 0 { + t.Fatal("expected to see no network events") + } + }) + }) +} diff --git a/internal/measurexlite/tls.go b/internal/measurexlite/tls.go index 2d881a7..c3cd098 100644 --- a/internal/measurexlite/tls.go +++ b/internal/measurexlite/tls.go @@ -57,6 +57,7 @@ func (tx *Trace) OnTLSHandshakeDone(started time.Time, remoteAddr string, config case tx.TLSHandshake <- NewArchivalTLSOrQUICHandshakeResult( tx.Index, started.Sub(tx.ZeroTime), + "tls", remoteAddr, config, state, @@ -74,9 +75,10 @@ func (tx *Trace) OnTLSHandshakeDone(started time.Time, remoteAddr string, config // NewArchivalTLSOrQUICHandshakeResult generates a model.ArchivalTLSOrQUICHandshakeResult // from the available information right after the TLS handshake returns. func NewArchivalTLSOrQUICHandshakeResult( - index int64, started time.Duration, address string, config *tls.Config, + index int64, started time.Duration, network string, address string, config *tls.Config, state tls.ConnectionState, err error, finished time.Duration) *model.ArchivalTLSOrQUICHandshakeResult { return &model.ArchivalTLSOrQUICHandshakeResult{ + Network: network, Address: address, CipherSuite: netxlite.TLSCipherSuiteString(state.CipherSuite), Failure: tracex.NewFailure(err), diff --git a/internal/measurexlite/tls_test.go b/internal/measurexlite/tls_test.go index de51f14..29b62de 100644 --- a/internal/measurexlite/tls_test.go +++ b/internal/measurexlite/tls_test.go @@ -120,6 +120,7 @@ func TestNewTLSHandshakerStdlib(t *testing.T) { } expectedFailure := "unknown_failure: mocked" expect := &model.ArchivalTLSOrQUICHandshakeResult{ + Network: "tls", Address: "1.1.1.1:443", CipherSuite: "", Failure: &expectedFailure, @@ -273,6 +274,7 @@ func TestNewTLSHandshakerStdlib(t *testing.T) { t.Fatal("expected to see a single TLSHandshake event") } expected := &model.ArchivalTLSOrQUICHandshakeResult{ + Network: "tls", Address: conn.RemoteAddr().String(), CipherSuite: netxlite.TLSCipherSuiteString(connState.CipherSuite), Failure: nil, diff --git a/internal/measurexlite/trace.go b/internal/measurexlite/trace.go index 946e4e2..fbb7c67 100644 --- a/internal/measurexlite/trace.go +++ b/internal/measurexlite/trace.go @@ -58,6 +58,10 @@ type Trace struct { // calls to the netxlite.NewTLSHandshakerStdlib factory. NewTLSHandshakerStdlibFn func(dl model.DebugLogger) model.TLSHandshaker + // NewDialerWithoutResolverFn is OPTIONAL and can be used to override + // calls to the netxlite.NewQUICDialerWithoutResolver factory. + NewQUICDialerWithoutResolverFn func(listener model.QUICListener, dl model.DebugLogger) model.QUICDialer + // DNSLookup is MANDATORY and buffers DNS Lookup observations. If you create // this channel manually, ensure it has some buffer. DNSLookup chan *model.ArchivalDNSLookupResult @@ -70,6 +74,10 @@ type Trace struct { // this channel manually, ensure it has some buffer. TLSHandshake chan *model.ArchivalTLSOrQUICHandshakeResult + // QUICHandshake is MANDATORY and buffers QUIC handshake observations. If you create + // this channel manually, ensure it has some buffer. + QUICHandshake chan *model.ArchivalTLSOrQUICHandshakeResult + // TimeNowFn is OPTIONAL and can be used to override calls to time.Now // to produce deterministic timing when testing. TimeNowFn func() time.Time @@ -94,6 +102,10 @@ const ( // TLSHandshakeBufferSize is the buffer for construcing // the Trace's TLSHandshake buffered channel. TLSHandshakeBufferSize = 8 + + // QUICHandshakeBufferSize is the buffer for constructing + // the Trace's QUICHandshake buffered channel. + QUICHandshakeBufferSize = 8 ) // NewTrace creates a new instance of Trace using default settings. @@ -128,6 +140,10 @@ func NewTrace(index int64, zeroTime time.Time) *Trace { chan *model.ArchivalTLSOrQUICHandshakeResult, TLSHandshakeBufferSize, ), + QUICHandshake: make( + chan *model.ArchivalTLSOrQUICHandshakeResult, + QUICHandshakeBufferSize, + ), TimeNowFn: nil, // use default ZeroTime: zeroTime, } @@ -178,6 +194,15 @@ func (tx *Trace) newTLSHandshakerStdlib(dl model.DebugLogger) model.TLSHandshake return netxlite.NewTLSHandshakerStdlib(dl) } +// newWUICDialerWithoutResolver indirectly calls netxlite.NewQUICDialerWithoutResolver +// thus allowing us to mock this func for testing. +func (tx *Trace) newQUICDialerWithoutResolver(listener model.QUICListener, dl model.DebugLogger) model.QUICDialer { + if tx.NewQUICDialerWithoutResolverFn != nil { + return tx.NewQUICDialerWithoutResolverFn(listener, dl) + } + return netxlite.NewQUICDialerWithoutResolver(listener, dl) +} + // TimeNow implements model.Trace.TimeNow. func (tx *Trace) TimeNow() time.Time { if tx.TimeNowFn != nil { diff --git a/internal/measurexlite/trace_test.go b/internal/measurexlite/trace_test.go index 854e625..2aa966b 100644 --- a/internal/measurexlite/trace_test.go +++ b/internal/measurexlite/trace_test.go @@ -6,9 +6,11 @@ import ( "errors" "net" "reflect" + "syscall" "testing" "time" + "github.com/lucas-clemente/quic-go" "github.com/ooni/probe-cli/v3/internal/model" "github.com/ooni/probe-cli/v3/internal/model/mocks" "github.com/ooni/probe-cli/v3/internal/netxlite" @@ -76,6 +78,12 @@ func TestNewTrace(t *testing.T) { } }) + t.Run("NewQUICDialerWithoutResolverFn is nil", func(t *testing.T) { + if trace.NewQUICDialerWithoutResolverFn != nil { + t.Fatal("expected nil NewQUICDialerQithoutResolverFn") + } + }) + t.Run("DNSLookup has the expected buffer size", func(t *testing.T) { ff := &testingx.FakeFiller{} var idx int @@ -133,6 +141,25 @@ func TestNewTrace(t *testing.T) { } }) + t.Run("QUICHandshake has the expected buffer size", func(t *testing.T) { + ff := &testingx.FakeFiller{} + var idx int + Loop: + for { + ev := &model.ArchivalTLSOrQUICHandshakeResult{} + ff.Fill(ev) + select { + case trace.QUICHandshake <- ev: + idx++ + default: + break Loop + } + } + if idx != QUICHandshakeBufferSize { + t.Fatal("invalid QUICHandshake channel buffer size") + } + }) + t.Run("TimeNowFn is nil", func(t *testing.T) { if trace.TimeNowFn != nil { t.Fatal("expected nil TimeNowFn") @@ -380,6 +407,73 @@ func TestTrace(t *testing.T) { }) }) + t.Run("NewQUICDialerWithoutResolverFn works as intended", func(t *testing.T) { + t.Run("when not nil", func(t *testing.T) { + mockedErr := errors.New("mocked") + tx := &Trace{ + NewQUICDialerWithoutResolverFn: func(listener model.QUICListener, dl model.DebugLogger) model.QUICDialer { + return &mocks.QUICDialer{ + MockDialContext: func(ctx context.Context, network, address string, + tlsConfig *tls.Config, quicConfig *quic.Config) (quic.EarlyConnection, error) { + return nil, mockedErr + }, + } + }, + } + qdx := tx.newQUICDialerWithoutResolver(&mocks.QUICListener{}, model.DiscardLogger) + ctx := context.Background() + qconn, err := qdx.DialContext(ctx, "udp", "1.1.1.1:443", &tls.Config{}, &quic.Config{}) + if !errors.Is(err, mockedErr) { + t.Fatal("unexpected err", err) + } + if qconn != nil { + t.Fatal("expected nil conn") + } + }) + + t.Run("when nil", func(t *testing.T) { + mockedErr := errors.New("mocked") + tx := &Trace{ + NewQUICDialerWithoutResolverFn: nil, // explicit + } + pconn := &mocks.UDPLikeConn{ + MockLocalAddr: func() net.Addr { + return &net.UDPAddr{ + Port: 0, + } + }, + MockRemoteAddr: func() net.Addr { + return &net.UDPAddr{ + Port: 0, + } + }, + MockSyscallConn: func() (syscall.RawConn, error) { + return nil, mockedErr + }, + MockClose: func() error { + return nil + }, + } + listener := &mocks.QUICListener{ + MockListen: func(addr *net.UDPAddr) (model.UDPLikeConn, error) { + return pconn, nil + }, + } + tlsConfig := &tls.Config{ + InsecureSkipVerify: true, + } + dialer := tx.newQUICDialerWithoutResolver(listener, model.DiscardLogger) + ctx := context.Background() + qconn, err := dialer.DialContext(ctx, "udp", "1.1.1.1:443", tlsConfig, &quic.Config{}) + if !errors.Is(err, mockedErr) { + t.Fatal("unexpected err", err) + } + if qconn != nil { + t.Fatal("expected nil conn") + } + }) + }) + t.Run("TimeNowFn works as intended", func(t *testing.T) { fixedTime := time.Date(2022, 01, 01, 00, 00, 00, 00, time.UTC) tx := &Trace{ diff --git a/internal/model/archival.go b/internal/model/archival.go index 42e0e84..34b35df 100644 --- a/internal/model/archival.go +++ b/internal/model/archival.go @@ -163,6 +163,7 @@ type ArchivalTCPConnectStatus struct { // // See https://github.com/ooni/spec/blob/master/data-formats/df-006-tlshandshake.md type ArchivalTLSOrQUICHandshakeResult struct { + Network string `json:"network"` Address string `json:"address"` CipherSuite string `json:"cipher_suite"` Failure *string `json:"failure"` diff --git a/internal/model/mocks/trace.go b/internal/model/mocks/trace.go index 363e4a2..11136e9 100644 --- a/internal/model/mocks/trace.go +++ b/internal/model/mocks/trace.go @@ -8,6 +8,7 @@ import ( "crypto/tls" "time" + "github.com/lucas-clemente/quic-go" "github.com/ooni/probe-cli/v3/internal/model" ) @@ -25,6 +26,11 @@ type Trace struct { MockOnTLSHandshakeDone func(started time.Time, remoteAddr string, config *tls.Config, state tls.ConnectionState, err error, finished time.Time) + + MockOnQUICHandshakeStart func(now time.Time, remoteAddrs string, config *quic.Config) + + MockOnQUICHandshakeDone func(started time.Time, remoteAddr string, qconn quic.EarlyConnection, + config *tls.Config, err error, finished time.Time) } var _ model.Trace = &Trace{} @@ -51,3 +57,12 @@ func (t *Trace) OnTLSHandshakeDone(started time.Time, remoteAddr string, config state tls.ConnectionState, err error, finished time.Time) { t.MockOnTLSHandshakeDone(started, remoteAddr, config, state, err, finished) } + +func (t *Trace) OnQUICHandshakeStart(now time.Time, remoteAddr string, config *quic.Config) { + t.MockOnQUICHandshakeStart(now, remoteAddr, config) +} + +func (t *Trace) OnQUICHandshakeDone(started time.Time, remoteAddr string, qconn quic.EarlyConnection, + config *tls.Config, err error, finished time.Time) { + t.MockOnQUICHandshakeDone(started, remoteAddr, qconn, config, err, finished) +} diff --git a/internal/model/mocks/trace_test.go b/internal/model/mocks/trace_test.go index 95aa995..b56a461 100644 --- a/internal/model/mocks/trace_test.go +++ b/internal/model/mocks/trace_test.go @@ -5,6 +5,7 @@ import ( "testing" "time" + "github.com/lucas-clemente/quic-go" "github.com/ooni/probe-cli/v3/internal/model" ) @@ -95,4 +96,37 @@ func TestTrace(t *testing.T) { t.Fatal("not called") } }) + + t.Run("OnQUICHandshakeStart", func(t *testing.T) { + var called bool + tx := &Trace{ + MockOnQUICHandshakeStart: func(now time.Time, remoteAddrs string, config *quic.Config) { + called = true + }, + } + tx.OnQUICHandshakeStart(time.Now(), "1.1.1.1:443", &quic.Config{}) + if !called { + t.Fatal("not called") + } + }) + + t.Run("OnQUICHandshakeDone", func(t *testing.T) { + var called bool + tx := &Trace{ + MockOnQUICHandshakeDone: func(started time.Time, remoteAddr string, qconn quic.EarlyConnection, config *tls.Config, err error, finished time.Time) { + called = true + }, + } + tx.OnQUICHandshakeDone( + time.Now(), + "1.1.1.1:443", + nil, + &tls.Config{}, + nil, + time.Now(), + ) + if !called { + t.Fatal("not called") + } + }) } diff --git a/internal/model/netx.go b/internal/model/netx.go index 4640d86..8dbd659 100644 --- a/internal/model/netx.go +++ b/internal/model/netx.go @@ -382,6 +382,41 @@ type Trace interface { // string returned by Error is an OONI error. OnTLSHandshakeDone(started time.Time, remoteAddr string, config *tls.Config, state tls.ConnectionState, err error, finished time.Time) + + // OnQUICHandshakeStart is called before the QUIC handshake. + // + // Arguments: + // + // - now is the moment before we start the handshake; + // + // - remoteAddr is the QUIC endpoint with which we are connecting: it will + // consist of an IP address and a port (e.g., 8.8.8.8:443, [::1]:5421); + // + // - config is the possibly-nil QUIC config we're using. + OnQUICHandshakeStart(now time.Time, remoteAddr string, quicConfig *quic.Config) + + // OnQUICHandshakeDone is called after the QUIC handshake. + // + // Arguments: + // + // - started is when we started the handshake; + // + // - remoteAddr is the QUIC endpoint with which we are connecting: it will + // consist of an IP address and a port (e.g., 8.8.8.8:443, [::1]:5421); + // + // - qconn is the QUIC connection we receive after the handshake: either + // a valid quic.EarlyConnection or nil; + // + // - config is the non-nil TLS config we are using; + // + // - err is the result of the handshake: either an error or nil; + // + // - finished is right after the handshake. + // + // The error passed to this function will always be wrapped such that the + // string returned by Error is an OONI error. + OnQUICHandshakeDone(started time.Time, remoteAddr string, qconn quic.EarlyConnection, + config *tls.Config, err error, finished time.Time) } // UDPLikeConn is a net.PacketConn with some extra functions diff --git a/internal/netxlite/quic.go b/internal/netxlite/quic.go index 24ddabc..8810cbd 100644 --- a/internal/netxlite/quic.go +++ b/internal/netxlite/quic.go @@ -134,8 +134,14 @@ func (d *quicDialerQUICGo) DialContext(ctx context.Context, network string, return nil, err } tlsConfig = d.maybeApplyTLSDefaults(tlsConfig, udpAddr.Port) + trace := ContextTraceOrDefault(ctx) + started := trace.TimeNow() + trace.OnQUICHandshakeStart(started, address, quicConfig) qconn, err := d.dialEarlyContext( ctx, pconn, udpAddr, address, tlsConfig, quicConfig) + finished := trace.TimeNow() + err = MaybeNewErrWrapper(ClassifyQUICHandshakeError, QUICHandshakeOperation, err) + trace.OnQUICHandshakeDone(started, address, qconn, tlsConfig, err, finished) if err != nil { pconn.Close() // we own it on failure return nil, err diff --git a/internal/netxlite/trace.go b/internal/netxlite/trace.go index 201b309..f364ae6 100644 --- a/internal/netxlite/trace.go +++ b/internal/netxlite/trace.go @@ -9,6 +9,7 @@ import ( "crypto/tls" "time" + "github.com/lucas-clemente/quic-go" "github.com/ooni/probe-cli/v3/internal/model" "github.com/ooni/probe-cli/v3/internal/runtimex" ) @@ -71,3 +72,12 @@ func (*traceDefault) OnTLSHandshakeDone(started time.Time, remoteAddr string, co state tls.ConnectionState, err error, finished time.Time) { // nothing } + +func (*traceDefault) OnQUICHandshakeStart(now time.Time, remoteAddr string, config *quic.Config) { + // nothing +} + +func (*traceDefault) OnQUICHandshakeDone(started time.Time, remoteAddr string, qconn quic.EarlyConnection, + config *tls.Config, err error, finished time.Time) { + // nothing +}