From 85664f1e31de0844f444af7c690a57628ff79ff7 Mon Sep 17 00:00:00 2001 From: Simone Basso Date: Mon, 7 Feb 2022 17:05:36 +0100 Subject: [PATCH] feat(torsf): collect tor logs, select rendezvous method, count bytes (#683) This diff contains significant improvements over the previous implementation of the torsf experiment. We add support for configuring different rendezvous methods after the convo at https://github.com/ooni/probe/issues/2004. In doing that, I've tried to use a terminology that is consistent with the names being actually used by tor developers. In terms of what to do next, this diff basically instruments torsf to always rendezvous using domain fronting. Yet, it's also possible to change the rendezvous method from the command line, when using miniooni, which allows to experiment a bit more. In the same vein, by default we use a persistent tor datadir, but it's also possible to use a temporary datadir using the cmdline. Here's how a generic invocation of `torsf` looks like: ```bash ./miniooni -O DisablePersistentDatadir=true \ -O RendezvousMethod=amp \ -O DisableProgress=true \ torsf ``` (The default is `DisablePersistentDatadir=false` and `RendezvousMethod=domain_fronting`.) With this implementation, we can start measuring whether snowflake and tor together can boostrap, which seems the most important thing to focus on at the beginning. Understanding why the bootstrap most often does not converge with a temporary datadir on Android devices remains instead an open problem for now. (I'll also update the relevant issues or create new issues after commit this.) We also address some methodology improvements that were proposed in https://github.com/ooni/probe/issues/1686. Namely: 1. we record the tor version; 2. we include the bootstrap percentage by reading the logs; 3. we set the anomaly key correctly; 4. we measure the bytes send and received (by `tor` not by `snowflake`, since doing it for snowflake seems more complex at this stage). What remains to be done is the possibility of including Snowflake events into the measurement, which is not possible until the new improvements at common/event in snowflake.git are included into a tagged version of snowflake itself. (I'll make sure to mention this aspect to @cohosh in https://github.com/ooni/probe/issues/2004.) --- internal/bytecounter/conn.go | 13 + internal/bytecounter/conn_test.go | 31 ++ internal/bytecounter/context.go | 40 ++ internal/bytecounter/context_test.go | 61 +++ internal/cmd/ptxclient/ptxclient.go | 43 -- internal/engine/experiment.go | 5 +- internal/engine/experiment/torsf/.gitignore | 1 + .../engine/experiment/torsf/testdata/tor.log | 31 ++ internal/engine/experiment/torsf/torsf.go | 173 ++++++-- .../engine/experiment/torsf/torsf_test.go | 383 +++++++++++++----- .../engine/experiment/urlgetter/getter.go | 2 +- internal/engine/mockable/mockable.go | 6 + internal/engine/netx/dialer/bytecounter.go | 33 +- .../engine/netx/dialer/bytecounter_test.go | 4 +- internal/engine/session.go | 11 +- internal/model/experiment.go | 1 + internal/ptx/dependencies.go | 8 - internal/ptx/dependencies_test.go | 11 - internal/ptx/obfs4.go | 3 +- internal/ptx/obfs4_test.go | 8 +- internal/ptx/ptx.go | 24 +- internal/ptx/snowflake.go | 147 +++++-- internal/ptx/snowflake_test.go | 102 ++++- internal/tunnel/config.go | 19 + internal/tunnel/config_test.go | 14 + internal/tunnel/fake.go | 19 +- internal/tunnel/fake_integration_test.go | 2 +- internal/tunnel/fake_test.go | 10 +- internal/tunnel/mocks/mocks.go | 37 ++ internal/tunnel/mocks/mocks_test.go | 60 +++ internal/tunnel/psiphon.go | 22 +- internal/tunnel/psiphon_integration_test.go | 2 +- internal/tunnel/psiphon_test.go | 10 +- internal/tunnel/tor.go | 31 +- internal/tunnel/tor_integration_test.go | 2 +- internal/tunnel/tor_test.go | 64 ++- internal/tunnel/tunnel.go | 29 +- internal/tunnel/tunnel_test.go | 8 +- .../experiment/torsf/chapter04/README.md | 6 +- .../experiment/torsf/chapter04/torsf.go | 8 +- 40 files changed, 1150 insertions(+), 334 deletions(-) create mode 100644 internal/bytecounter/context.go create mode 100644 internal/bytecounter/context_test.go delete mode 100644 internal/cmd/ptxclient/ptxclient.go create mode 100644 internal/engine/experiment/torsf/.gitignore create mode 100644 internal/engine/experiment/torsf/testdata/tor.log delete mode 100644 internal/ptx/dependencies.go delete mode 100644 internal/ptx/dependencies_test.go create mode 100644 internal/tunnel/mocks/mocks.go create mode 100644 internal/tunnel/mocks/mocks_test.go diff --git a/internal/bytecounter/conn.go b/internal/bytecounter/conn.go index 2201686..954009d 100644 --- a/internal/bytecounter/conn.go +++ b/internal/bytecounter/conn.go @@ -24,3 +24,16 @@ func (c *Conn) Write(p []byte) (int, error) { c.Counter.CountBytesSent(count) return count, err } + +// Wrap returns a new conn that uses the given counter. +func Wrap(conn net.Conn, counter *Counter) net.Conn { + return &Conn{Conn: conn, Counter: counter} +} + +// MaybeWrap is like wrap if counter is not nil, otherwise it's a no-op. +func MaybeWrap(conn net.Conn, counter *Counter) net.Conn { + if counter == nil { + return conn + } + return Wrap(conn, counter) +} diff --git a/internal/bytecounter/conn_test.go b/internal/bytecounter/conn_test.go index 3c193fc..30b1b9a 100644 --- a/internal/bytecounter/conn_test.go +++ b/internal/bytecounter/conn_test.go @@ -64,3 +64,34 @@ func TestConnWorksOnFailure(t *testing.T) { t.Fatal("unexpected number of bytes sent") } } + +func TestWrap(t *testing.T) { + conn := &mocks.Conn{} + counter := New() + nconn := Wrap(conn, counter) + _, good := nconn.(*Conn) + if !good { + t.Fatal("did not wrap") + } +} + +func TestMaybeWrap(t *testing.T) { + t.Run("with nil counter", func(t *testing.T) { + conn := &mocks.Conn{} + nconn := MaybeWrap(conn, nil) + _, good := nconn.(*mocks.Conn) + if !good { + t.Fatal("did not wrap") + } + }) + + t.Run("with legit counter", func(t *testing.T) { + conn := &mocks.Conn{} + counter := New() + nconn := MaybeWrap(conn, counter) + _, good := nconn.(*Conn) + if !good { + t.Fatal("did not wrap") + } + }) +} diff --git a/internal/bytecounter/context.go b/internal/bytecounter/context.go new file mode 100644 index 0000000..4521e97 --- /dev/null +++ b/internal/bytecounter/context.go @@ -0,0 +1,40 @@ +package bytecounter + +import ( + "context" + "net" +) + +type byteCounterSessionKey struct{} + +// ContextSessionByteCounter retrieves the session byte counter from the context +func ContextSessionByteCounter(ctx context.Context) *Counter { + counter, _ := ctx.Value(byteCounterSessionKey{}).(*Counter) + return counter +} + +// WithSessionByteCounter assigns the session byte counter to the context. +func WithSessionByteCounter(ctx context.Context, counter *Counter) context.Context { + return context.WithValue(ctx, byteCounterSessionKey{}, counter) +} + +type byteCounterExperimentKey struct{} + +// ContextExperimentByteCounter retrieves the experiment byte counter from the context +func ContextExperimentByteCounter(ctx context.Context) *Counter { + counter, _ := ctx.Value(byteCounterExperimentKey{}).(*Counter) + return counter +} + +// WithExperimentByteCounter assigns the experiment byte counter to the context. +func WithExperimentByteCounter(ctx context.Context, counter *Counter) context.Context { + return context.WithValue(ctx, byteCounterExperimentKey{}, counter) +} + +// MaybeWrapWithContextByteCounters wraps a conn with the byte counters +// that have previosuly been configured into a context. +func MaybeWrapWithContextByteCounters(ctx context.Context, conn net.Conn) net.Conn { + conn = MaybeWrap(conn, ContextExperimentByteCounter(ctx)) + conn = MaybeWrap(conn, ContextSessionByteCounter(ctx)) + return conn +} diff --git a/internal/bytecounter/context_test.go b/internal/bytecounter/context_test.go new file mode 100644 index 0000000..793c2d8 --- /dev/null +++ b/internal/bytecounter/context_test.go @@ -0,0 +1,61 @@ +package bytecounter + +import ( + "context" + "net" + "testing" + + "github.com/ooni/probe-cli/v3/internal/model/mocks" +) + +func TestSessionByteCounter(t *testing.T) { + counter := New() + ctx := context.Background() + ctx = WithSessionByteCounter(ctx, counter) + outer := ContextSessionByteCounter(ctx) + if outer != counter { + t.Fatal("unexpected result") + } +} + +func TestExperimentByteCounter(t *testing.T) { + counter := New() + ctx := context.Background() + ctx = WithExperimentByteCounter(ctx, counter) + outer := ContextExperimentByteCounter(ctx) + if outer != counter { + t.Fatal("unexpected result") + } +} + +func TestMaybeWrapWithContextByteCounters(t *testing.T) { + var conn net.Conn = &mocks.Conn{ + MockRead: func(b []byte) (int, error) { + return len(b), nil + }, + MockWrite: func(b []byte) (int, error) { + return len(b), nil + }, + } + sessCounter := New() + expCounter := New() + ctx := context.Background() + ctx = WithSessionByteCounter(ctx, sessCounter) + ctx = WithExperimentByteCounter(ctx, expCounter) + conn = MaybeWrapWithContextByteCounters(ctx, conn) + buf := make([]byte, 128) + conn.Read(buf) + conn.Write(buf) + if sessCounter.Received.Load() != 128 { + t.Fatal("invalid value") + } + if sessCounter.Sent.Load() != 128 { + t.Fatal("invalid value") + } + if expCounter.Received.Load() != 128 { + t.Fatal("invalid value") + } + if expCounter.Sent.Load() != 128 { + t.Fatal("invalid value") + } +} diff --git a/internal/cmd/ptxclient/ptxclient.go b/internal/cmd/ptxclient/ptxclient.go deleted file mode 100644 index b3706b7..0000000 --- a/internal/cmd/ptxclient/ptxclient.go +++ /dev/null @@ -1,43 +0,0 @@ -// Command ptxclient implements a pluggable transports CLI client. This command -// is only meant for testing and is not production ready. -package main - -import ( - "flag" - "fmt" - "os" - "os/signal" - - "github.com/apex/log" - "github.com/ooni/probe-cli/v3/internal/ptx" -) - -func main() { - mode := flag.String("m", "snowflake", "one of snowflake and obfs4") - verbose := flag.Bool("v", false, "enable verbose mode") - flag.Parse() - if *verbose { - log.SetLevel(log.DebugLevel) - } - var dialer ptx.PTDialer - switch *mode { - case "snowflake": - dialer = &ptx.SnowflakeDialer{} - case "obfs4": - dialer = ptx.DefaultTestingOBFS4Bridge() - default: - fmt.Fprintf(os.Stderr, "unknown pluggable transport: %s\n", *mode) - os.Exit(1) - } - listener := &ptx.Listener{ - PTDialer: dialer, - Logger: log.Log, - } - if err := listener.Start(); err != nil { - log.WithError(err).Fatal("listener.Start failed") - } - sigch := make(chan os.Signal, 1) - signal.Notify(sigch, os.Interrupt) - <-sigch - listener.Stop() -} diff --git a/internal/engine/experiment.go b/internal/engine/experiment.go index 87be9be..053eb0a 100644 --- a/internal/engine/experiment.go +++ b/internal/engine/experiment.go @@ -11,7 +11,6 @@ import ( "github.com/ooni/probe-cli/v3/internal/bytecounter" "github.com/ooni/probe-cli/v3/internal/engine/geolocate" - "github.com/ooni/probe-cli/v3/internal/engine/netx/dialer" "github.com/ooni/probe-cli/v3/internal/engine/netx/httptransport" "github.com/ooni/probe-cli/v3/internal/engine/probeservices" "github.com/ooni/probe-cli/v3/internal/model" @@ -161,8 +160,8 @@ func (e *Experiment) MeasureAsync( if err != nil { return nil, err } - ctx = dialer.WithSessionByteCounter(ctx, e.session.byteCounter) - ctx = dialer.WithExperimentByteCounter(ctx, e.byteCounter) + ctx = bytecounter.WithSessionByteCounter(ctx, e.session.byteCounter) + ctx = bytecounter.WithExperimentByteCounter(ctx, e.byteCounter) var async model.ExperimentMeasurerAsync if v, okay := e.measurer.(model.ExperimentMeasurerAsync); okay { async = v diff --git a/internal/engine/experiment/torsf/.gitignore b/internal/engine/experiment/torsf/.gitignore new file mode 100644 index 0000000..c0aad4e --- /dev/null +++ b/internal/engine/experiment/torsf/.gitignore @@ -0,0 +1 @@ +/torsf diff --git a/internal/engine/experiment/torsf/testdata/tor.log b/internal/engine/experiment/torsf/testdata/tor.log new file mode 100644 index 0000000..cd5282c --- /dev/null +++ b/internal/engine/experiment/torsf/testdata/tor.log @@ -0,0 +1,31 @@ +Feb 04 15:04:29.000 [notice] Tor 0.4.6.9 opening new log file. +Feb 04 15:04:29.360 [notice] We compiled with OpenSSL 101010cf: OpenSSL 1.1.1l FIPS 24 Aug 2021 and we are running with OpenSSL 101010cf: 1.1.1l. These two versions should be binary compatible. +Feb 04 15:04:29.363 [notice] Tor 0.4.6.9 running on Linux with Libevent 2.1.12-stable, OpenSSL 1.1.1l, Zlib 1.2.11, Liblzma 5.2.5, Libzstd 1.5.2 and Glibc 2.34 as libc. +Feb 04 15:04:29.363 [notice] Tor can't help you if you use it wrong! Learn how to be safe at https://www.torproject.org/download/download#warning +Feb 04 15:04:29.363 [warn] Tor was compiled with zstd 1.5.1, but is running with zstd 1.5.2. For safety, we'll avoid using advanced zstd functionality. +Feb 04 15:04:29.363 [notice] Read configuration file "/home/sbs/.miniooni/tunnel/torsf/tor/torrc-2981077975". +Feb 04 15:04:29.366 [notice] Opening Control listener on 127.0.0.1:0 +Feb 04 15:04:29.367 [notice] Control listener listening on port 41423. +Feb 04 15:04:29.367 [notice] Opened Control listener connection (ready) on 127.0.0.1:41423 +Feb 04 15:04:29.367 [notice] DisableNetwork is set. Tor will not make or accept non-control network connections. Shutting down all existing connections. +Feb 04 15:04:29.000 [notice] Parsing GEOIP IPv4 file /usr/share/tor/geoip. +Feb 04 15:04:29.000 [notice] Parsing GEOIP IPv6 file /usr/share/tor/geoip6. +Feb 04 15:04:29.000 [notice] Bootstrapped 0% (starting): Starting +Feb 04 15:04:29.000 [notice] Starting with guard context "bridges" +Feb 04 15:04:29.000 [notice] new bridge descriptor 'flakey4' (cached): $2B280B23E1107BB62ABFC40DDCC8824814F80A72~flakey4 [1zOHpg+FxqQfi/6jDLtCpHHqBTH8gjYmCKXkus1D5Ko] at 192.0.2.3 +Feb 04 15:04:29.000 [notice] Delaying directory fetches: DisableNetwork is set. +Feb 04 15:04:29.000 [notice] New control connection opened from 127.0.0.1. +Feb 04 15:04:29.000 [notice] Opening Socks listener on 127.0.0.1:0 +Feb 04 15:04:29.000 [notice] Socks listener listening on port 42089. +Feb 04 15:04:29.000 [notice] Opened Socks listener connection (ready) on 127.0.0.1:42089 +Feb 04 15:04:29.000 [notice] Tor 0.4.6.9 opening log file. +Feb 04 15:04:29.000 [notice] Bootstrapped 1% (conn_pt): Connecting to pluggable transport +Feb 04 15:04:30.000 [notice] Bootstrapped 2% (conn_done_pt): Connected to pluggable transport +Feb 04 15:04:30.000 [notice] Bootstrapped 10% (conn_done): Connected to a relay +Feb 04 15:06:20.000 [notice] Bootstrapped 14% (handshake): Handshaking with a relay +Feb 04 15:06:24.000 [notice] Bootstrapped 15% (handshake_done): Handshake with a relay done +Feb 04 15:06:24.000 [notice] Bootstrapped 75% (enough_dirinfo): Loaded enough directory info to build circuits +Feb 04 15:06:24.000 [notice] Bootstrapped 95% (circuit_create): Establishing a Tor circuit +Feb 04 15:06:26.000 [notice] new bridge descriptor 'flakey4' (fresh): $2B280B23E1107BB62ABFC40DDCC8824814F80A72~flakey4 [1zOHpg+FxqQfi/6jDLtCpHHqBTH8gjYmCKXkus1D5Ko] at 192.0.2.3 +Feb 04 15:06:39.000 [notice] Bootstrapped 100% (done): Done +Feb 04 15:06:39.000 [notice] Catching signal TERM, exiting cleanly. diff --git a/internal/engine/experiment/torsf/torsf.go b/internal/engine/experiment/torsf/torsf.go index a96b466..f201e03 100644 --- a/internal/engine/experiment/torsf/torsf.go +++ b/internal/engine/experiment/torsf/torsf.go @@ -5,11 +5,17 @@ package torsf import ( + "bytes" "context" + "errors" "fmt" + "os" "path" + "regexp" "time" + "github.com/apex/log" + "github.com/ooni/probe-cli/v3/internal/bytecounter" "github.com/ooni/probe-cli/v3/internal/engine/netx/archival" "github.com/ooni/probe-cli/v3/internal/model" "github.com/ooni/probe-cli/v3/internal/ptx" @@ -17,11 +23,18 @@ import ( ) // testVersion is the tor experiment version. -const testVersion = "0.1.1" +const testVersion = "0.2.0" // Config contains the experiment config. type Config struct { + // DisablePersistentDatadir disables using a persistent datadir. + DisablePersistentDatadir bool `ooni:"Disable using a persistent tor datadir"` + + // DisableProgress disables printing progress messages. DisableProgress bool `ooni:"Disable printing progress messages"` + + // RendezvousMethod allows to choose the method with which to rendezvous. + RendezvousMethod string `ooni:"Choose the method with which to rendezvous. Must be one of amp and domain_fronting. Leaving this field empty means we should use the default."` } // TestKeys contains the experiment's result. @@ -31,6 +44,18 @@ type TestKeys struct { // Failure contains the failure string or nil. Failure *string `json:"failure"` + + // PersistentDatadir indicates whether we're using a persistent tor datadir. + PersistentDatadir bool `json:"persistent_datadir"` + + // RendezvousMethod contains the method used to perform the rendezvous. + RendezvousMethod string `json:"rendezvous_method"` + + // TorLogs contains the bootstrap logs. + TorLogs []string `json:"tor_logs"` + + // TorVersion contains the version of tor (if it's possible to obtain it). + TorVersion string `json:"tor_version"` } // Measurer performs the measurement. @@ -44,7 +69,8 @@ type Measurer struct { // mockStartTunnel is an optional function that allows us to override the // default tunnel.Start function used to start a tunnel. - mockStartTunnel func(ctx context.Context, config *tunnel.Config) (tunnel.Tunnel, error) + mockStartTunnel func( + ctx context.Context, config *tunnel.Config) (tunnel.Tunnel, tunnel.DebugInfo, error) } // ExperimentName implements model.ExperimentMeasurer.ExperimentName. @@ -73,22 +99,27 @@ func (m *Measurer) Run( ctx context.Context, sess model.ExperimentSession, measurement *model.Measurement, callbacks model.ExperimentCallbacks, ) error { + ptl, sfdialer, err := m.setup(ctx, sess.Logger()) + if err != nil { + // we cannot setup the experiment + return err + } + defer ptl.Stop() m.registerExtensions(measurement) - testkeys := &TestKeys{} - measurement.TestKeys = testkeys start := time.Now() const maxRuntime = 600 * time.Second ctx, cancel := context.WithTimeout(ctx, maxRuntime) defer cancel() - errch := make(chan error) + tkch := make(chan *TestKeys) ticker := time.NewTicker(2 * time.Second) defer ticker.Stop() - go m.run(ctx, sess, testkeys, errch) + go m.bootstrap(ctx, sess, tkch, ptl, sfdialer) for { select { - case err := <-errch: + case tk := <-tkch: + measurement.TestKeys = tk callbacks.OnProgress(1.0, "torsf experiment is finished") - return err + return nil case <-ticker.C: if !m.config.DisableProgress { elapsedTime := time.Since(start) @@ -101,28 +132,50 @@ func (m *Measurer) Run( } } -// run runs the bootstrap. This function ONLY returns an error when -// there has been a fundamental error starting the test. This behavior -// follows the expectations for the ExperimentMeasurer.Run method. -func (m *Measurer) run(ctx context.Context, - sess model.ExperimentSession, testkeys *TestKeys, errch chan<- error) { - sfdialer := &ptx.SnowflakeDialer{} +// setup prepares for running the torsf experiment. Returns a valid ptx listener +// and snowflake dialer on success. Returns an error on failure. On success, +// remember to Stop the ptx listener when you're done. +func (m *Measurer) setup(ctx context.Context, + logger model.Logger) (*ptx.Listener, *ptx.SnowflakeDialer, error) { + rm, err := ptx.NewSnowflakeRendezvousMethod(m.config.RendezvousMethod) + if err != nil { + // cannot run the experiment with unknown rendezvous method + return nil, nil, err + } + sfdialer := ptx.NewSnowflakeDialerWithRendezvousMethod(rm) ptl := &ptx.Listener{ - PTDialer: sfdialer, - Logger: sess.Logger(), + ExperimentByteCounter: bytecounter.ContextExperimentByteCounter(ctx), + Logger: logger, + PTDialer: sfdialer, + SessionByteCounter: bytecounter.ContextSessionByteCounter(ctx), } if err := m.startListener(ptl.Start); err != nil { - testkeys.Failure = archival.NewFailure(err) // This error condition mostly means "I could not open a local // listening port", which strikes as fundamental failure. - errch <- err - return + return nil, nil, err } - defer ptl.Stop() - tun, err := m.startTunnel()(ctx, &tunnel.Config{ + logger.Infof("torsf: rendezvous method: '%s'", m.config.RendezvousMethod) + return ptl, sfdialer, nil +} + +// bootstrap runs the bootstrap. +func (m *Measurer) bootstrap(ctx context.Context, sess model.ExperimentSession, + out chan<- *TestKeys, ptl *ptx.Listener, sfdialer *ptx.SnowflakeDialer) { + tk := &TestKeys{ + BootstrapTime: 0, + Failure: nil, + PersistentDatadir: !m.config.DisablePersistentDatadir, + RendezvousMethod: sfdialer.RendezvousMethod.Name(), + } + sess.Logger().Infof( + "torsf: disable persistent datadir: %+v", m.config.DisablePersistentDatadir) + defer func() { + out <- tk + }() + tun, debugInfo, err := m.startTunnel()(ctx, &tunnel.Config{ Name: "tor", Session: sess, - TunnelDir: path.Join(sess.TempDir(), "torsf"), + TunnelDir: path.Join(m.baseTunnelDir(sess), "torsf"), Logger: sess.Logger(), TorArgs: []string{ "UseBridges", "1", @@ -130,18 +183,61 @@ func (m *Measurer) run(ctx context.Context, "Bridge", sfdialer.AsBridgeArgument(), }, }) + tk.TorVersion = debugInfo.Version + m.readTorLogs(sess.Logger(), tk, debugInfo.LogFilePath) if err != nil { // Note: archival.NewFailure scrubs IP addresses - testkeys.Failure = archival.NewFailure(err) - // This error condition means we could not bootstrap with snowflake - // for $reasons, so the experiment didn't fail, rather it did record - // that something prevented snowflake from running. - errch <- nil + tk.Failure = archival.NewFailure(err) return } defer tun.Stop() - testkeys.BootstrapTime = tun.BootstrapTime().Seconds() - errch <- nil + tk.BootstrapTime = tun.BootstrapTime().Seconds() +} + +// torProgressRegexp helps to extract progress info from logs. +// +// See https://regex101.com/r/3YfIed/1. +var torProgressRegexp = regexp.MustCompile( + `^[A-Za-z0-9.: ]+ \[notice\] Bootstrapped [0-9]+% \([a-zA-z]+\): [A-Za-z0-9 ]+$`) + +// readTorLogs attempts to read and include the tor logs into +// the test keys if this operation is possible. +// +// This function aims to _only_ include notice information about +// bootstrap according to the torProgressRegexp regexp. +// +// Tor is know to be good software that does not break its output +// unnecessarily and that does not include PII into its logs unless +// explicitly asked to. This fact gives me confidence that we can +// safely include this subset of the logs into the results. +// +// On this note, I think it's safe to include timestamps from the +// logs into the output, since we have a timestamp for the whole +// experiment already, so we don't leak much more by also including +// the Tor proper timestamps into the results. +func (m *Measurer) readTorLogs(logger model.Logger, tk *TestKeys, logFilePath string) { + if logFilePath == "" { + log.Warn("the tunnel claims there is no log file") + return + } + data, err := os.ReadFile(logFilePath) + if err != nil { + log.Warnf("could not read tor logs: %s", err.Error()) + return + } + for _, bline := range bytes.Split(data, []byte("\n")) { + if torProgressRegexp.Match(bline) { + tk.TorLogs = append(tk.TorLogs, string(bline)) + } + } +} + +// baseTunnelDir returns the base directory to use for tunnelling +func (m *Measurer) baseTunnelDir(sess model.ExperimentSession) string { + if m.config.DisablePersistentDatadir { + return sess.TempDir() + } + return sess.TunnelDir() } // startListener either calls f or mockStartListener depending @@ -155,7 +251,7 @@ func (m *Measurer) startListener(f func() error) error { // startTunnel returns the proper function to start a tunnel. func (m *Measurer) startTunnel() func( - ctx context.Context, config *tunnel.Config) (tunnel.Tunnel, error) { + ctx context.Context, config *tunnel.Config) (tunnel.Tunnel, tunnel.DebugInfo, error) { if m.mockStartTunnel != nil { return m.mockStartTunnel } @@ -175,7 +271,22 @@ type SummaryKeys struct { IsAnomaly bool `json:"-"` } +var ( + // errInvalidTestKeysType indicates the test keys type is invalid. + errInvalidTestKeysType = errors.New("torsf: invalid test keys type") + + //errNilTestKeys indicates that the test keys are nil. + errNilTestKeys = errors.New("torsf: nil test keys") +) + // GetSummaryKeys implements model.ExperimentMeasurer.GetSummaryKeys. func (m *Measurer) GetSummaryKeys(measurement *model.Measurement) (interface{}, error) { - return SummaryKeys{IsAnomaly: false}, nil + testkeys, good := measurement.TestKeys.(*TestKeys) + if !good { + return nil, errInvalidTestKeysType + } + if testkeys == nil { + return nil, errNilTestKeys + } + return SummaryKeys{IsAnomaly: testkeys.Failure != nil}, nil } diff --git a/internal/engine/experiment/torsf/torsf_test.go b/internal/engine/experiment/torsf/torsf_test.go index f6d198b..1117840 100644 --- a/internal/engine/experiment/torsf/torsf_test.go +++ b/internal/engine/experiment/torsf/torsf_test.go @@ -3,14 +3,16 @@ package torsf import ( "context" "errors" - "net/url" + "path/filepath" "testing" "time" - "github.com/apex/log" + "github.com/ooni/probe-cli/v3/internal/atomicx" "github.com/ooni/probe-cli/v3/internal/engine/mockable" "github.com/ooni/probe-cli/v3/internal/model" + "github.com/ooni/probe-cli/v3/internal/ptx" "github.com/ooni/probe-cli/v3/internal/tunnel" + "github.com/ooni/probe-cli/v3/internal/tunnel/mocks" ) func TestExperimentNameAndVersion(t *testing.T) { @@ -18,85 +20,34 @@ func TestExperimentNameAndVersion(t *testing.T) { if m.ExperimentName() != "torsf" { t.Fatal("invalid experiment name") } - if m.ExperimentVersion() != "0.1.1" { + if m.ExperimentVersion() != "0.2.0" { t.Fatal("invalid experiment version") } } -// mockedTunnel is a mocked tunnel. -type mockedTunnel struct { - bootstrapTime time.Duration - proxyURL *url.URL -} - -// BootstrapTime implements Tunnel.BootstrapTime. -func (mt *mockedTunnel) BootstrapTime() time.Duration { - return mt.bootstrapTime -} - -// SOCKS5ProxyURL implements Tunnel.SOCKS5ProxyURL. -func (mt *mockedTunnel) SOCKS5ProxyURL() *url.URL { - return mt.proxyURL -} - -// Stop implements Tunnel.Stop. -func (mt *mockedTunnel) Stop() { - // nothing -} - -func TestSuccessWithMockedTunnelStart(t *testing.T) { - bootstrapTime := 400 * time.Millisecond +func TestFailureWithInvalidRendezvousMethod(t *testing.T) { m := &Measurer{ - config: Config{}, - mockStartTunnel: func(ctx context.Context, config *tunnel.Config) (tunnel.Tunnel, error) { - // run for some time so we also exercise printing progress. - time.Sleep(bootstrapTime) - return &mockedTunnel{ - bootstrapTime: time.Duration(bootstrapTime), - }, nil + config: Config{ + DisablePersistentDatadir: false, + DisableProgress: false, + RendezvousMethod: "antani", }, + mockStartTunnel: nil, } ctx := context.Background() measurement := &model.Measurement{} - sess := &mockable.Session{} + sess := &mockable.Session{ + MockableLogger: model.DiscardLogger, + } callbacks := &model.PrinterCallbacks{ - Logger: log.Log, + Logger: model.DiscardLogger, } - if err := m.Run(ctx, sess, measurement, callbacks); err != nil { - t.Fatal(err) + err := m.Run(ctx, sess, measurement, callbacks) + if !errors.Is(err, ptx.ErrSnowflakeNoSuchRendezvousMethod) { + t.Fatal("unexpected error", err) } - tk := measurement.TestKeys.(*TestKeys) - if tk.BootstrapTime != bootstrapTime.Seconds() { - t.Fatal("unexpected bootstrap time") - } -} - -func TestFailureToStartTunnel(t *testing.T) { - expected := errors.New("mocked error") - m := &Measurer{ - config: Config{}, - mockStartTunnel: func(ctx context.Context, config *tunnel.Config) (tunnel.Tunnel, error) { - return nil, expected - }, - } - ctx := context.Background() - measurement := &model.Measurement{} - sess := &mockable.Session{} - callbacks := &model.PrinterCallbacks{ - Logger: log.Log, - } - if err := m.Run(ctx, sess, measurement, callbacks); err != nil { - t.Fatal(err) - } - tk := measurement.TestKeys.(*TestKeys) - if tk.BootstrapTime != 0 { - t.Fatal("unexpected bootstrap time") - } - if tk.Failure == nil { - t.Fatal("unexpectedly nil failure string") - } - if *tk.Failure != "unknown_failure: mocked error" { - t.Fatal("unexpected failure string", *tk.Failure) + if measurement.TestKeys != nil { + t.Fatal("expected nil test keys") } } @@ -112,11 +63,130 @@ func TestFailureToStartPTXListener(t *testing.T) { measurement := &model.Measurement{} sess := &mockable.Session{} callbacks := &model.PrinterCallbacks{ - Logger: log.Log, + Logger: model.DiscardLogger, } if err := m.Run(ctx, sess, measurement, callbacks); !errors.Is(err, expected) { t.Fatal("not the error we expected", err) } + if tk := measurement.TestKeys; tk != nil { + t.Fatal("expected nil bootstrap time here") + } +} + +func TestSuccessWithMockedTunnelStart(t *testing.T) { + bootstrapTime := 3 * time.Second + called := &atomicx.Int64{} + m := &Measurer{ + config: Config{}, + mockStartTunnel: func( + ctx context.Context, config *tunnel.Config) (tunnel.Tunnel, tunnel.DebugInfo, error) { + // run for some time so we also exercise printing progress. + time.Sleep(bootstrapTime) + return &mocks.Tunnel{ + MockBootstrapTime: func() time.Duration { + return bootstrapTime + }, + MockStop: func() { + called.Add(1) + }, + }, tunnel.DebugInfo{ + Name: "tor", + LogFilePath: filepath.Join("testdata", "tor.log"), + }, nil + }, + } + ctx := context.Background() + measurement := &model.Measurement{} + sess := &mockable.Session{ + MockableLogger: model.DiscardLogger, + } + callbacks := &model.PrinterCallbacks{ + Logger: model.DiscardLogger, + } + if err := m.Run(ctx, sess, measurement, callbacks); err != nil { + t.Fatal(err) + } + if called.Load() != 1 { + t.Fatal("stop was not called") + } + tk := measurement.TestKeys.(*TestKeys) + if tk.BootstrapTime != bootstrapTime.Seconds() { + t.Fatal("unexpected bootstrap time") + } + if tk.Failure != nil { + t.Fatal("unexpected failure") + } + if !tk.PersistentDatadir { + t.Fatal("unexpected persistent data dir") + } + if tk.RendezvousMethod != "domain_fronting" { + t.Fatal("unexpected rendezvous method") + } + if count := len(tk.TorLogs); count != 9 { + t.Fatal("unexpected length of tor logs", count) + } +} + +func TestWithCancelledContext(t *testing.T) { + // This test calls the real tunnel.Start function so we cover + // it but fails immediately because of the cancelled ctx. + m := &Measurer{ + config: Config{}, + } + ctx, cancel := context.WithCancel(context.Background()) + cancel() // fail immediately + measurement := &model.Measurement{} + sess := &mockable.Session{ + MockableLogger: model.DiscardLogger, + } + callbacks := &model.PrinterCallbacks{ + Logger: model.DiscardLogger, + } + if err := m.Run(ctx, sess, measurement, callbacks); err != nil { + t.Fatal(err) + } + tk := measurement.TestKeys.(*TestKeys) + if tk.BootstrapTime != 0 { + t.Fatal("unexpected bootstrap time") + } + if *tk.Failure != "interrupted" { + t.Fatal("unexpected failure") + } + if !tk.PersistentDatadir { + t.Fatal("unexpected persistent data dir") + } + if tk.RendezvousMethod != "domain_fronting" { + t.Fatal("unexpected rendezvous method") + } + if len(tk.TorLogs) != 0 { + t.Fatal("unexpected length of tor logs") + } +} + +func TestFailureToStartTunnel(t *testing.T) { + expected := errors.New("mocked error") + m := &Measurer{ + config: Config{}, + mockStartTunnel: func( + ctx context.Context, config *tunnel.Config) (tunnel.Tunnel, tunnel.DebugInfo, error) { + return nil, + tunnel.DebugInfo{ + Name: "tor", + LogFilePath: filepath.Join("testdata", "tor.log"), + }, expected + }, + } + ctx := context.Background() + measurement := &model.Measurement{} + sess := &mockable.Session{ + MockableLogger: model.DiscardLogger, + } + callbacks := &model.PrinterCallbacks{ + Logger: model.DiscardLogger, + } + if err := m.Run(ctx, sess, measurement, callbacks); err != nil { + t.Fatal(err) + } tk := measurement.TestKeys.(*TestKeys) if tk.BootstrapTime != 0 { t.Fatal("unexpected bootstrap time") @@ -127,41 +197,150 @@ func TestFailureToStartPTXListener(t *testing.T) { if *tk.Failure != "unknown_failure: mocked error" { t.Fatal("unexpected failure string", *tk.Failure) } + if !tk.PersistentDatadir { + t.Fatal("unexpected persistent datadir") + } + if tk.RendezvousMethod != "domain_fronting" { + t.Fatal("unexpected rendezvous method") + } + if count := len(tk.TorLogs); count != 9 { + t.Fatal("unexpected length of tor logs", count) + } } -func TestStartWithCancelledContext(t *testing.T) { - m := &Measurer{config: Config{}} - ctx, cancel := context.WithCancel(context.Background()) - cancel() // fail immediately - measurement := &model.Measurement{} - sess := &mockable.Session{} - callbacks := &model.PrinterCallbacks{ - Logger: log.Log, - } - if err := m.Run(ctx, sess, measurement, callbacks); err != nil { - t.Fatal(err) - } - tk := measurement.TestKeys.(*TestKeys) - if tk.BootstrapTime != 0 { - t.Fatal("unexpected bootstrap time") - } - if tk.Failure == nil { - t.Fatal("unexpected nil failure") - } - if *tk.Failure != "interrupted" { - t.Fatal("unexpected failure string", *tk.Failure) - } +func TestBaseTunnelDir(t *testing.T) { + t.Run("without persistent data dir", func(t *testing.T) { + m := &Measurer{ + config: Config{ + DisablePersistentDatadir: true, + }, + } + sess := &mockable.Session{ + MockableTunnelDir: "a", + MockableTempDir: "b", + } + dir := m.baseTunnelDir(sess) + if dir != "b" { + t.Fatal("unexpected base tunnel dir", dir) + } + }) + + t.Run("with persistent data dir", func(t *testing.T) { + m := &Measurer{ + config: Config{ + DisablePersistentDatadir: false, + }, + } + sess := &mockable.Session{ + MockableTunnelDir: "a", + MockableTempDir: "b", + } + dir := m.baseTunnelDir(sess) + if dir != "a" { + t.Fatal("unexpected base tunnel dir", dir) + } + }) +} + +func TestReadTorLogs(t *testing.T) { + t.Run("with empty file path", func(t *testing.T) { + m := &Measurer{} + logger := model.DiscardLogger + tk := &TestKeys{} + m.readTorLogs(logger, tk, "") + if len(tk.TorLogs) != 0 { + t.Fatal("expected no tor logs") + } + }) + + t.Run("with nonexistent file path", func(t *testing.T) { + m := &Measurer{} + logger := model.DiscardLogger + tk := &TestKeys{} + m.readTorLogs(logger, tk, filepath.Join("testdata", "nonexistent")) + if len(tk.TorLogs) != 0 { + t.Fatal("expected no tor logs") + } + }) + + t.Run("with existing file path", func(t *testing.T) { + m := &Measurer{} + logger := model.DiscardLogger + tk := &TestKeys{} + m.readTorLogs(logger, tk, filepath.Join("testdata", "tor.log")) + if count := len(tk.TorLogs); count != 9 { + t.Fatal("unexpected number of tor logs", count) + } + }) } func TestGetSummaryKeys(t *testing.T) { - measurement := &model.Measurement{} - m := &Measurer{} - sk, err := m.GetSummaryKeys(measurement) - if err != nil { - t.Fatal(err) - } - rsk := sk.(SummaryKeys) - if rsk.IsAnomaly { - t.Fatal("expected no anomaly here") - } + t.Run("in case of untyped nil TestKeys", func(t *testing.T) { + measurement := &model.Measurement{ + TestKeys: nil, + } + m := &Measurer{} + _, err := m.GetSummaryKeys(measurement) + if !errors.Is(err, errInvalidTestKeysType) { + t.Fatal("unexpected error", err) + } + }) + + t.Run("in case of typed nil TestKeys", func(t *testing.T) { + var tk *TestKeys + measurement := &model.Measurement{ + TestKeys: tk, + } + m := &Measurer{} + _, err := m.GetSummaryKeys(measurement) + if !errors.Is(err, errNilTestKeys) { + t.Fatal("unexpected error", err) + } + }) + + t.Run("in case of invalid TestKeys type", func(t *testing.T) { + measurement := &model.Measurement{ + TestKeys: make(chan int), + } + m := &Measurer{} + _, err := m.GetSummaryKeys(measurement) + if !errors.Is(err, errInvalidTestKeysType) { + t.Fatal("unexpected error", err) + } + }) + + t.Run("in case of success", func(t *testing.T) { + measurement := &model.Measurement{ + TestKeys: &TestKeys{ + Failure: nil, + }, + } + m := &Measurer{} + sk, err := m.GetSummaryKeys(measurement) + if err != nil { + t.Fatal(err) + } + rsk := sk.(SummaryKeys) + if rsk.IsAnomaly { + t.Fatal("expected no anomaly here") + } + }) + + t.Run("in case of failure", func(t *testing.T) { + failure := "generic_timeout_error" + measurement := &model.Measurement{ + TestKeys: &TestKeys{ + Failure: &failure, + }, + } + m := &Measurer{} + sk, err := m.GetSummaryKeys(measurement) + if err != nil { + t.Fatal(err) + } + rsk := sk.(SummaryKeys) + if !rsk.IsAnomaly { + t.Fatal("expected anomaly here") + } + }) } diff --git a/internal/engine/experiment/urlgetter/getter.go b/internal/engine/experiment/urlgetter/getter.go index eab383a..4e6ca5b 100644 --- a/internal/engine/experiment/urlgetter/getter.go +++ b/internal/engine/experiment/urlgetter/getter.go @@ -111,7 +111,7 @@ func (g Getter) get(ctx context.Context, saver *trace.Saver) (TestKeys, error) { if err != nil { return tk, err } - tun, err := tunnel.Start(ctx, &tunnel.Config{ + tun, _, err := tunnel.Start(ctx, &tunnel.Config{ Name: g.Config.Tunnel, Session: g.Session, TorArgs: g.Session.TorArgs(), diff --git a/internal/engine/mockable/mockable.go b/internal/engine/mockable/mockable.go index 690a7c9..1893002 100644 --- a/internal/engine/mockable/mockable.go +++ b/internal/engine/mockable/mockable.go @@ -34,6 +34,7 @@ type Session struct { MockableTempDir string MockableTorArgs []string MockableTorBinary string + MockableTunnelDir string MockableUserAgent string } @@ -135,6 +136,11 @@ func (sess *Session) TorBinary() string { return sess.MockableTorBinary } +// TunnelDir implements ExperimentSession.TunnelDir. +func (sess *Session) TunnelDir() string { + return sess.MockableTunnelDir +} + // UserAgent implements ExperimentSession.UserAgent func (sess *Session) UserAgent() string { return sess.MockableUserAgent diff --git a/internal/engine/netx/dialer/bytecounter.go b/internal/engine/netx/dialer/bytecounter.go index 4544510..447fb4b 100644 --- a/internal/engine/netx/dialer/bytecounter.go +++ b/internal/engine/netx/dialer/bytecounter.go @@ -21,37 +21,6 @@ func (d *byteCounterDialer) DialContext( if err != nil { return nil, err } - if exp := contextExperimentByteCounter(ctx); exp != nil { - conn = &bytecounter.Conn{Conn: conn, Counter: exp} - } - if sess := contextSessionByteCounter(ctx); sess != nil { - conn = &bytecounter.Conn{Conn: conn, Counter: sess} - } + conn = bytecounter.MaybeWrapWithContextByteCounters(ctx, conn) return conn, nil } - -type byteCounterSessionKey struct{} - -// contextSessionByteCounter retrieves the session byte counter from the context -func contextSessionByteCounter(ctx context.Context) *bytecounter.Counter { - counter, _ := ctx.Value(byteCounterSessionKey{}).(*bytecounter.Counter) - return counter -} - -// WithSessionByteCounter assigns the session byte counter to the context. -func WithSessionByteCounter(ctx context.Context, counter *bytecounter.Counter) context.Context { - return context.WithValue(ctx, byteCounterSessionKey{}, counter) -} - -type byteCounterExperimentKey struct{} - -// contextExperimentByteCounter retrieves the experiment byte counter from the context -func contextExperimentByteCounter(ctx context.Context) *bytecounter.Counter { - counter, _ := ctx.Value(byteCounterExperimentKey{}).(*bytecounter.Counter) - return counter -} - -// WithExperimentByteCounter assigns the experiment byte counter to the context. -func WithExperimentByteCounter(ctx context.Context, counter *bytecounter.Counter) context.Context { - return context.WithValue(ctx, byteCounterExperimentKey{}, counter) -} diff --git a/internal/engine/netx/dialer/bytecounter_test.go b/internal/engine/netx/dialer/bytecounter_test.go index 95a8eae..48b7b76 100644 --- a/internal/engine/netx/dialer/bytecounter_test.go +++ b/internal/engine/netx/dialer/bytecounter_test.go @@ -39,12 +39,12 @@ func TestByteCounterNormalUsage(t *testing.T) { } sess := bytecounter.New() ctx := context.Background() - ctx = WithSessionByteCounter(ctx, sess) + ctx = bytecounter.WithSessionByteCounter(ctx, sess) if err := dorequest(ctx, "http://www.google.com"); err != nil { t.Fatal(err) } exp := bytecounter.New() - ctx = WithExperimentByteCounter(ctx, exp) + ctx = bytecounter.WithExperimentByteCounter(ctx, exp) if err := dorequest(ctx, "http://facebook.com"); err != nil { t.Fatal(err) } diff --git a/internal/engine/session.go b/internal/engine/session.go index 4efb4bf..c5dd155 100644 --- a/internal/engine/session.go +++ b/internal/engine/session.go @@ -95,6 +95,9 @@ type Session struct { // may need to pass to urlgetter when it uses a tor tunnel. torBinary string + // tunnelDir is the directory used by tunnels. + tunnelDir string + // tunnel is the optional tunnel that we may be using. It is created // by NewSession and it is cleaned up by Close. tunnel tunnel.Tunnel @@ -163,6 +166,7 @@ func NewSession(ctx context.Context, config SessionConfig) (*Session, error) { tempDir: tempDir, torArgs: config.TorArgs, torBinary: config.TorBinary, + tunnelDir: config.TunnelDir, } proxyURL := config.ProxyURL if proxyURL != nil { @@ -170,7 +174,7 @@ func NewSession(ctx context.Context, config SessionConfig) (*Session, error) { case "psiphon", "tor", "fake": config.Logger.Infof( "starting '%s' tunnel; please be patient...", proxyURL.Scheme) - tunnel, err := tunnel.Start(ctx, &tunnel.Config{ + tunnel, _, err := tunnel.Start(ctx, &tunnel.Config{ Logger: config.Logger, Name: proxyURL.Scheme, Session: &sessionTunnelEarlySession{}, @@ -204,6 +208,11 @@ func NewSession(ctx context.Context, config SessionConfig) (*Session, error) { return sess, nil } +// TunnelDir returns the persistent directory used by tunnels. +func (s *Session) TunnelDir() string { + return s.tunnelDir +} + // KibiBytesReceived accounts for the KibiBytes received by the HTTP clients // managed by this session so far, including experiments. func (s *Session) KibiBytesReceived() float64 { diff --git a/internal/model/experiment.go b/internal/model/experiment.go index 44b71ea..1e8a8a3 100644 --- a/internal/model/experiment.go +++ b/internal/model/experiment.go @@ -23,6 +23,7 @@ type ExperimentSession interface { TempDir() string TorArgs() []string TorBinary() string + TunnelDir() string UserAgent() string } diff --git a/internal/ptx/dependencies.go b/internal/ptx/dependencies.go deleted file mode 100644 index 6675e27..0000000 --- a/internal/ptx/dependencies.go +++ /dev/null @@ -1,8 +0,0 @@ -package ptx - -import ( - "github.com/ooni/probe-cli/v3/internal/model" -) - -// defaultLogger is the default silentLogger instance. -var defaultLogger model.Logger = model.DiscardLogger diff --git a/internal/ptx/dependencies_test.go b/internal/ptx/dependencies_test.go deleted file mode 100644 index d28c211..0000000 --- a/internal/ptx/dependencies_test.go +++ /dev/null @@ -1,11 +0,0 @@ -package ptx - -import "testing" - -func TestCoverSilentLogger(t *testing.T) { - // let us not be distracted by uncovered lines that can - // easily be covered, we can easily cover defaultLogger - defaultLogger.Debugf("foo") - defaultLogger.Infof("bar") - defaultLogger.Warnf("baz") -} diff --git a/internal/ptx/obfs4.go b/internal/ptx/obfs4.go index b364a86..b33edac 100644 --- a/internal/ptx/obfs4.go +++ b/internal/ptx/obfs4.go @@ -125,7 +125,8 @@ type obfs4CancellableDialer struct { } // dial performs the dial. -func (d *obfs4CancellableDialer) dial(ctx context.Context, network, address string) (net.Conn, error) { +func (d *obfs4CancellableDialer) dial( + ctx context.Context, network, address string) (net.Conn, error) { connch, errch := make(chan net.Conn), make(chan error, 1) go func() { defer close(d.done) // signal we're joining diff --git a/internal/ptx/obfs4_test.go b/internal/ptx/obfs4_test.go index f3a5876..3625a32 100644 --- a/internal/ptx/obfs4_test.go +++ b/internal/ptx/obfs4_test.go @@ -74,7 +74,8 @@ func TestOBFS4DialerFailsWithConnectionErrorAndContextExpiration(t *testing.T) { wg := &sync.WaitGroup{} wg.Add(1) o4d.UnderlyingDialer = &mocks.Dialer{ - MockDialContext: func(ctx context.Context, network string, address string) (net.Conn, error) { + MockDialContext: func( + ctx context.Context, network string, address string) (net.Conn, error) { cancel() <-sigch wg.Done() @@ -114,8 +115,9 @@ func TestOBFS4DialerWorksWithContextExpiration(t *testing.T) { called := &atomicx.Int64{} o4d := DefaultTestingOBFS4Bridge() o4d.UnderlyingDialer = &mocks.Dialer{ - MockDialContext: func(ctx context.Context, network string, address string) (net.Conn, error) { - // We cancel the context before returning the error, which makes + MockDialContext: func( + ctx context.Context, network string, address string) (net.Conn, error) { + // We cancel the context before returning the conn, which makes // the context cancellation happen before us returning. cancel() conn, err := net.Dial(network, address) diff --git a/internal/ptx/ptx.go b/internal/ptx/ptx.go index 083b020..51daa41 100644 --- a/internal/ptx/ptx.go +++ b/internal/ptx/ptx.go @@ -46,6 +46,7 @@ import ( "sync" pt "git.torproject.org/pluggable-transports/goptlib.git" + "github.com/ooni/probe-cli/v3/internal/bytecounter" "github.com/ooni/probe-cli/v3/internal/model" "github.com/ooni/probe-cli/v3/internal/netxlite" ) @@ -69,15 +70,23 @@ type PTDialer interface { // you fill the mandatory fields before using it. Do not modify public // fields after you called Start, since this causes data races. type Listener struct { + // ExperimentByteCounter is the OPTIONAL byte counter that + // counts the bytes consumed by the experiment. + ExperimentByteCounter *bytecounter.Counter + + // Logger is the OPTIONAL logger. When not set, this library + // will not emit logs. (But the underlying pluggable transport + // may still emit its own log messages.) + Logger model.Logger + // PTDialer is the MANDATORY pluggable transports dialer // to use. Both SnowflakeDialer and OBFS4Dialer implement this // interface and can be thus safely used here. PTDialer PTDialer - // Logger is the optional logger. When not set, this library - // will not emit logs. (But the underlying pluggable transport - // may still emit its own log messages.) - Logger model.Logger + // SessionByteCounter is the OPTIONAL byte counter that + // counts the bytes consumed by the session. + SessionByteCounter *bytecounter.Counter // mu provides mutual exclusion for accessing internals. mu sync.Mutex @@ -100,7 +109,7 @@ func (lst *Listener) logger() model.Logger { if lst.Logger != nil { return lst.Logger } - return defaultLogger + return model.DiscardLogger } // forward forwards the traffic from left to right and from right to left @@ -151,6 +160,11 @@ func (lst *Listener) handleSocksConn(ctx context.Context, socksConn ptxSocksConn lst.logger().Warnf("ptx: ContextDialer.DialContext error: %s", err) return err // used for testing } + // We _must_ wrap the ptConn. Wrapping the socks conn leads us to + // count the sent bytes as received and the received bytes as sent: + // bytes flow in the opposite direction there for the socks conn. + ptConn = bytecounter.MaybeWrap(ptConn, lst.SessionByteCounter) + ptConn = bytecounter.MaybeWrap(ptConn, lst.ExperimentByteCounter) lst.forwardWithContext(ctx, socksConn, ptConn) // transfer ownership return nil // used for testing } diff --git a/internal/ptx/snowflake.go b/internal/ptx/snowflake.go index bb6a913..c2ae139 100644 --- a/internal/ptx/snowflake.go +++ b/internal/ptx/snowflake.go @@ -2,20 +2,130 @@ package ptx import ( "context" + "errors" "net" sflib "git.torproject.org/pluggable-transports/snowflake.git/v2/client/lib" "github.com/ooni/probe-cli/v3/internal/stuninput" ) -// SnowflakeDialer is a dialer for snowflake. When optional fields are -// not specified, we use defaults from the snowflake repository. +// SnowflakeRendezvousMethod is the method which with we perform the rendezvous. +type SnowflakeRendezvousMethod interface { + // Name is the name of the method. + Name() string + + // AMPCacheURL returns a suitable AMP cache URL. + AMPCacheURL() string + + // BrokerURL returns a suitable broker URL. + BrokerURL() string + + // FrontDomain returns a suitable front domain. + FrontDomain() string +} + +// NewSnowflakeRendezvousMethodDomainFronting is a rendezvous method +// that uses domain fronting to perform the rendezvous. +func NewSnowflakeRendezvousMethodDomainFronting() SnowflakeRendezvousMethod { + return &snowflakeRendezvousMethodDomainFronting{} +} + +type snowflakeRendezvousMethodDomainFronting struct{} + +func (d *snowflakeRendezvousMethodDomainFronting) Name() string { + return "domain_fronting" +} + +func (d *snowflakeRendezvousMethodDomainFronting) AMPCacheURL() string { + return "" +} + +func (d *snowflakeRendezvousMethodDomainFronting) BrokerURL() string { + return "https://snowflake-broker.torproject.net.global.prod.fastly.net/" +} + +func (d *snowflakeRendezvousMethodDomainFronting) FrontDomain() string { + return "cdn.sstatic.net" +} + +// NewSnowflakeRendezvousMethodAMP is a rendezvous method that +// uses the AMP cache to perform the rendezvous. +func NewSnowflakeRendezvousMethodAMP() SnowflakeRendezvousMethod { + return &snowflakeRendezvousMethodAMP{} +} + +type snowflakeRendezvousMethodAMP struct{} + +func (d *snowflakeRendezvousMethodAMP) Name() string { + return "amp" +} + +func (d *snowflakeRendezvousMethodAMP) AMPCacheURL() string { + return "https://cdn.ampproject.org/" +} + +func (d *snowflakeRendezvousMethodAMP) BrokerURL() string { + return "https://snowflake-broker.torproject.net/" +} + +func (d *snowflakeRendezvousMethodAMP) FrontDomain() string { + return "www.google.com" +} + +// ErrSnowflakeNoSuchRendezvousMethod indicates the given rendezvous +// method is not supported by this implementation. +var ErrSnowflakeNoSuchRendezvousMethod = errors.New("ptx: unsupported rendezvous method") + +// NewSnowflakeRendezvousMethod creates a new rendezvous method by name. We currently +// support the following rendezvous methods: +// +// 1. "domain_fronting" uses domain fronting with the sstatic.net CDN; +// +// 2. "" means default and it is currently equivalent to "domain_fronting" (but +// we don't guarantee that this default may change over time); +// +// 3. "amp" uses the AMP cache. +// +// Returns either a valid rendezvous method or an error. +func NewSnowflakeRendezvousMethod(method string) (SnowflakeRendezvousMethod, error) { + switch method { + case "domain_fronting", "": + return NewSnowflakeRendezvousMethodDomainFronting(), nil + case "amp": + return NewSnowflakeRendezvousMethodAMP(), nil + default: + return nil, ErrSnowflakeNoSuchRendezvousMethod + } +} + +// SnowflakeDialer is a dialer for snowflake. You SHOULD either use a factory +// for constructing this type or set the fields marked as MANDATORY. type SnowflakeDialer struct { - // newClientTransport is an optional hook for creating + // RendezvousMethod is the MANDATORY rendezvous method to use. + RendezvousMethod SnowflakeRendezvousMethod + + // newClientTransport is an OPTIONAL hook for creating // an alternative snowflakeTransport in testing. newClientTransport func(config sflib.ClientConfig) (snowflakeTransport, error) } +// NewSnowflakeDialer creates a SnowflakeDialer with default settings. +func NewSnowflakeDialer() *SnowflakeDialer { + return &SnowflakeDialer{ + RendezvousMethod: NewSnowflakeRendezvousMethodDomainFronting(), + newClientTransport: nil, + } +} + +// NewSnowflakeDialerWithRendezvousMethod creates a SnowflakeDialer +// using the given RendezvousMethod explicitly. +func NewSnowflakeDialerWithRendezvousMethod(m SnowflakeRendezvousMethod) *SnowflakeDialer { + return &SnowflakeDialer{ + RendezvousMethod: m, + newClientTransport: nil, + } +} + // snowflakeTransport is anything that allows us to dial a snowflake type snowflakeTransport interface { Dial() (net.Conn, error) @@ -32,9 +142,9 @@ func (d *SnowflakeDialer) dialContext( ctx context.Context) (net.Conn, chan interface{}, error) { done := make(chan interface{}) txp, err := d.newSnowflakeClient(sflib.ClientConfig{ - BrokerURL: d.brokerURL(), - AmpCacheURL: d.ampCacheURL(), - FrontDomain: d.frontDomain(), + BrokerURL: d.RendezvousMethod.BrokerURL(), + AmpCacheURL: d.RendezvousMethod.AMPCacheURL(), + FrontDomain: d.RendezvousMethod.FrontDomain(), ICEAddresses: d.iceAddresses(), KeepLocalAddresses: false, Max: d.maxSnowflakes(), @@ -68,35 +178,14 @@ func (d *SnowflakeDialer) dialContext( // newSnowflakeClient allows us to call a mock rather than // the real sflib.NewSnowflakeClient. -func (d *SnowflakeDialer) newSnowflakeClient(config sflib.ClientConfig) (snowflakeTransport, error) { +func (d *SnowflakeDialer) newSnowflakeClient( + config sflib.ClientConfig) (snowflakeTransport, error) { if d.newClientTransport != nil { return d.newClientTransport(config) } return sflib.NewSnowflakeClient(config) } -// ampCacheURL returns a suitable AMP cache URL. -func (d *SnowflakeDialer) ampCacheURL() string { - // I tried using the following AMP cache and always got: - // - // 2022/01/19 16:51:28 AMP cache rendezvous response: 500 Internal Server Error - // - // So I disabled the AMP cache until we figure it out. - // - //return "https://cdn.ampproject.org/" - return "" -} - -// brokerURL returns a suitable broker URL. -func (d *SnowflakeDialer) brokerURL() string { - return "https://snowflake-broker.torproject.net.global.prod.fastly.net/" -} - -// frontDomain returns a suitable front domain. -func (d *SnowflakeDialer) frontDomain() string { - return "cdn.sstatic.net" -} - // iceAddresses returns suitable ICE addresses. func (d *SnowflakeDialer) iceAddresses() []string { return stuninput.AsSnowflakeInput() diff --git a/internal/ptx/snowflake_test.go b/internal/ptx/snowflake_test.go index 7cde8e6..7c8c74f 100644 --- a/internal/ptx/snowflake_test.go +++ b/internal/ptx/snowflake_test.go @@ -11,12 +11,107 @@ import ( "github.com/ooni/probe-cli/v3/internal/model/mocks" ) +func TestSnowflakeMethodDomainFronting(t *testing.T) { + meth := NewSnowflakeRendezvousMethodDomainFronting() + if meth.AMPCacheURL() != "" { + t.Fatal("invalid amp cache URL") + } + const brokerURL = "https://snowflake-broker.torproject.net.global.prod.fastly.net/" + if meth.BrokerURL() != brokerURL { + t.Fatal("invalid broker URL") + } + const frontDomain = "cdn.sstatic.net" + if meth.FrontDomain() != frontDomain { + t.Fatal("invalid front domain") + } + if meth.Name() != "domain_fronting" { + t.Fatal("invalid name") + } +} + +func TestSnowflakeMethodAMP(t *testing.T) { + meth := NewSnowflakeRendezvousMethodAMP() + const ampCacheURL = "https://cdn.ampproject.org/" + if meth.AMPCacheURL() != ampCacheURL { + t.Fatal("invalid amp cache URL") + } + const brokerURL = "https://snowflake-broker.torproject.net/" + if meth.BrokerURL() != brokerURL { + t.Fatal("invalid broker URL") + } + const frontDomain = "www.google.com" + if meth.FrontDomain() != frontDomain { + t.Fatal("invalid front domain") + } + if meth.Name() != "amp" { + t.Fatal("invalid name") + } +} + +func TestNewSnowflakeRendezvousMethod(t *testing.T) { + t.Run("for domain_fronted", func(t *testing.T) { + meth, err := NewSnowflakeRendezvousMethod("domain_fronting") + if err != nil { + t.Fatal(err) + } + if _, ok := meth.(*snowflakeRendezvousMethodDomainFronting); !ok { + t.Fatal("unexpected method type") + } + }) + + t.Run("for empty string", func(t *testing.T) { + meth, err := NewSnowflakeRendezvousMethod("") + if err != nil { + t.Fatal(err) + } + if _, ok := meth.(*snowflakeRendezvousMethodDomainFronting); !ok { + t.Fatal("unexpected method type") + } + }) + + t.Run("for amp", func(t *testing.T) { + meth, err := NewSnowflakeRendezvousMethod("amp") + if err != nil { + t.Fatal(err) + } + if _, ok := meth.(*snowflakeRendezvousMethodAMP); !ok { + t.Fatal("unexpected method type") + } + }) + + t.Run("for another value", func(t *testing.T) { + meth, err := NewSnowflakeRendezvousMethod("amptani") + if !errors.Is(err, ErrSnowflakeNoSuchRendezvousMethod) { + t.Fatal("unexpected error", err) + } + if meth != nil { + t.Fatal("unexpected method value") + } + }) +} + +func TestNewSnowflakeDialer(t *testing.T) { + dialer := NewSnowflakeDialer() + _, ok := dialer.RendezvousMethod.(*snowflakeRendezvousMethodDomainFronting) + if !ok { + t.Fatal("invalid rendezvous method type") + } +} + +func TestNewSnowflakeDialerWithRendezvousMethod(t *testing.T) { + meth := NewSnowflakeRendezvousMethodAMP() + dialer := NewSnowflakeDialerWithRendezvousMethod(meth) + if meth != dialer.RendezvousMethod { + t.Fatal("invalid rendezvous method value") + } +} + func TestSnowflakeDialerWorks(t *testing.T) { // This test may sadly run for a very long time (~10s) if testing.Short() { t.Skip("skip test in short mode") } - sfd := &SnowflakeDialer{} + sfd := NewSnowflakeDialer() conn, err := sfd.DialContext(context.Background()) if err != nil { t.Fatal(err) @@ -48,6 +143,7 @@ var _ snowflakeTransport = &mockableSnowflakeTransport{} func TestSnowflakeDialerWorksWithMocks(t *testing.T) { sfd := &SnowflakeDialer{ + RendezvousMethod: NewSnowflakeRendezvousMethodDomainFronting(), newClientTransport: func(config sflib.ClientConfig) (snowflakeTransport, error) { return &mockableSnowflakeTransport{ MockDial: func() (net.Conn, error) { @@ -80,6 +176,7 @@ func TestSnowflakeDialerWorksWithMocks(t *testing.T) { func TestSnowflakeDialerCannotCreateTransport(t *testing.T) { expected := errors.New("mocked error") sfd := &SnowflakeDialer{ + RendezvousMethod: NewSnowflakeRendezvousMethodDomainFronting(), newClientTransport: func(config sflib.ClientConfig) (snowflakeTransport, error) { return nil, expected }, @@ -96,6 +193,7 @@ func TestSnowflakeDialerCannotCreateTransport(t *testing.T) { func TestSnowflakeDialerCannotCreateConnWithNoContextExpiration(t *testing.T) { expected := errors.New("mocked error") sfd := &SnowflakeDialer{ + RendezvousMethod: NewSnowflakeRendezvousMethodDomainFronting(), newClientTransport: func(config sflib.ClientConfig) (snowflakeTransport, error) { return &mockableSnowflakeTransport{ MockDial: func() (net.Conn, error) { @@ -118,6 +216,7 @@ func TestSnowflakeDialerCannotCreateConnWithContextExpiration(t *testing.T) { defer cancel() expected := errors.New("mocked error") sfd := &SnowflakeDialer{ + RendezvousMethod: NewSnowflakeRendezvousMethodDomainFronting(), newClientTransport: func(config sflib.ClientConfig) (snowflakeTransport, error) { return &mockableSnowflakeTransport{ MockDial: func() (net.Conn, error) { @@ -141,6 +240,7 @@ func TestSnowflakeDialerWorksWithWithCancelledContext(t *testing.T) { ctx, cancel := context.WithCancel(context.Background()) defer cancel() sfd := &SnowflakeDialer{ + RendezvousMethod: NewSnowflakeRendezvousMethodDomainFronting(), newClientTransport: func(config sflib.ClientConfig) (snowflakeTransport, error) { return &mockableSnowflakeTransport{ MockDial: func() (net.Conn, error) { diff --git a/internal/tunnel/config.go b/internal/tunnel/config.go index 32ed0fd..75bfc65 100644 --- a/internal/tunnel/config.go +++ b/internal/tunnel/config.go @@ -2,6 +2,7 @@ package tunnel import ( "context" + "errors" "net" "os" @@ -66,6 +67,9 @@ type Config struct { // testTorStart allows us to mock tor.Start. testTorStart func(ctx context.Context, conf *tor.StartConf) (*tor.Tor, error) + // testTorProtocolInfo allows us to mock getting protocol info. + testTorProtocolInfo func(tor *tor.Tor) (*control.ProtocolInfo, error) + // testTorEnableNetwork allows us to fake a failure when // telling to the tor daemon to enable the network. testTorEnableNetwork func(ctx context.Context, tor *tor.Tor, wait bool) error @@ -163,6 +167,21 @@ func (c *Config) torStart(ctx context.Context, conf *tor.StartConf) (*tor.Tor, e return tor.Start(ctx, conf) } +// errNoTorControl indicate you passed us a tor with a nil control field. +var errNoTorControl = errors.New("tunnel: no tor control") + +// torProtocolInfo calls either testTorProtocolInfo or the +// proper function to get back protocol information. +func (c *Config) torProtocolInfo(tor *tor.Tor) (*control.ProtocolInfo, error) { + if c.testTorProtocolInfo != nil { + return c.testTorProtocolInfo(tor) + } + if tor.Control == nil { + return nil, errNoTorControl + } + return tor.Control.ProtocolInfo() +} + // torEnableNetwork calls either testTorEnableNetwork or tor.EnableNetwork. func (c *Config) torEnableNetwork(ctx context.Context, tor *tor.Tor, wait bool) error { if c.testTorEnableNetwork != nil { diff --git a/internal/tunnel/config_test.go b/internal/tunnel/config_test.go index 9484da7..62edad9 100644 --- a/internal/tunnel/config_test.go +++ b/internal/tunnel/config_test.go @@ -6,6 +6,7 @@ import ( "testing" "github.com/apex/log" + "github.com/cretz/bine/tor" "github.com/ooni/probe-cli/v3/internal/model" ) @@ -108,3 +109,16 @@ func TestConfigTorBinary(t *testing.T) { verifyExpectations(t, config, expected, nil) }) } + +func TestConfigTorProtocolInfo(t *testing.T) { + t.Run("with nil Control field", func(t *testing.T) { + config := &Config{} + protocolInfo, err := config.torProtocolInfo(&tor.Tor{}) + if !errors.Is(err, errNoTorControl) { + t.Fatal("unexpected error", err) + } + if protocolInfo != nil { + t.Fatal("expected nil protocol info") + } + }) +} diff --git a/internal/tunnel/fake.go b/internal/tunnel/fake.go index dd53eb2..327a132 100644 --- a/internal/tunnel/fake.go +++ b/internal/tunnel/fake.go @@ -39,7 +39,7 @@ func (t *fakeTunnel) SOCKS5ProxyURL() *url.URL { } // fakeStart starts the fake tunnel. -func fakeStart(ctx context.Context, config *Config) (Tunnel, error) { +func fakeStart(ctx context.Context, config *Config) (Tunnel, DebugInfo, error) { // do the same things other tunnels do: // // 1. abort if context is cancelled @@ -50,25 +50,30 @@ func fakeStart(ctx context.Context, config *Config) (Tunnel, error) { // // after that, it's all fake and we just create a simple // socks5 server that we can use + debugInfo := DebugInfo{ + LogFilePath: "", + Name: "fake", + Version: "", + } select { case <-ctx.Done(): - return nil, ctx.Err() // simplifies unit testing this code + return nil, debugInfo, ctx.Err() // simplifies unit testing this code default: } if config.TunnelDir == "" { - return nil, ErrEmptyTunnelDir + return nil, debugInfo, ErrEmptyTunnelDir } if err := config.mkdirAll(config.TunnelDir, 0700); err != nil { - return nil, err + return nil, debugInfo, err } server, err := config.socks5New(&socks5.Config{}) if err != nil { - return nil, err + return nil, debugInfo, err } start := time.Now() listener, err := config.netListen("tcp", "127.0.0.1:0") if err != nil { - return nil, err + return nil, debugInfo, err } bootstrapTime := time.Since(start) go server.Serve(listener) @@ -76,5 +81,5 @@ func fakeStart(ctx context.Context, config *Config) (Tunnel, error) { addr: listener.Addr(), bootstrapTime: bootstrapTime, listener: listener, - }, nil + }, debugInfo, nil } diff --git a/internal/tunnel/fake_integration_test.go b/internal/tunnel/fake_integration_test.go index 366c3e3..33978ca 100644 --- a/internal/tunnel/fake_integration_test.go +++ b/internal/tunnel/fake_integration_test.go @@ -26,7 +26,7 @@ func TestFakeStartStop(t *testing.T) { if err != nil { t.Fatal(err) } - tunnel, err := tunnel.Start(context.Background(), &tunnel.Config{ + tunnel, _, err := tunnel.Start(context.Background(), &tunnel.Config{ Name: "fake", Session: sess, TunnelDir: tunnelDir, diff --git a/internal/tunnel/fake_test.go b/internal/tunnel/fake_test.go index e2b0abf..6021337 100644 --- a/internal/tunnel/fake_test.go +++ b/internal/tunnel/fake_test.go @@ -14,7 +14,7 @@ func TestFakeWithCancelledContext(t *testing.T) { ctx, cancel := context.WithCancel(context.Background()) cancel() // immediately fail sess := &MockableSession{} - tunnel, err := fakeStart(ctx, &Config{ + tunnel, _, err := fakeStart(ctx, &Config{ Session: sess, TunnelDir: "testdata", }) @@ -29,7 +29,7 @@ func TestFakeWithCancelledContext(t *testing.T) { func TestFakeWithEmptyTunnelDir(t *testing.T) { ctx := context.Background() sess := &MockableSession{} - tunnel, err := fakeStart(ctx, &Config{ + tunnel, _, err := fakeStart(ctx, &Config{ Session: sess, TunnelDir: "", }) @@ -45,7 +45,7 @@ func TestFakeWithFailingMkdirAll(t *testing.T) { expected := errors.New("mocked error") ctx := context.Background() sess := &MockableSession{} - tunnel, err := fakeStart(ctx, &Config{ + tunnel, _, err := fakeStart(ctx, &Config{ Session: sess, TunnelDir: "testdata", testMkdirAll: func(dir string, mode os.FileMode) error { @@ -64,7 +64,7 @@ func TestFakeSocks5NewFails(t *testing.T) { expected := errors.New("mocked error") ctx := context.Background() sess := &MockableSession{} - tunnel, err := fakeStart(ctx, &Config{ + tunnel, _, err := fakeStart(ctx, &Config{ Session: sess, TunnelDir: "testdata", testSocks5New: func(conf *socks5.Config) (*socks5.Server, error) { @@ -83,7 +83,7 @@ func TestFakeNetListenFails(t *testing.T) { expected := errors.New("mocked error") ctx := context.Background() sess := &MockableSession{} - tunnel, err := fakeStart(ctx, &Config{ + tunnel, _, err := fakeStart(ctx, &Config{ Session: sess, TunnelDir: "testdata", testNetListen: func(network, address string) (net.Listener, error) { diff --git a/internal/tunnel/mocks/mocks.go b/internal/tunnel/mocks/mocks.go new file mode 100644 index 0000000..abd42ea --- /dev/null +++ b/internal/tunnel/mocks/mocks.go @@ -0,0 +1,37 @@ +// Package mocks contains mocks for tunnel. +package mocks + +import ( + "net/url" + "time" + + "github.com/ooni/probe-cli/v3/internal/tunnel" +) + +// Tunnel allows mocking a tunnel. +type Tunnel struct { + // MockBootstrapTime allows to mock BootstrapTime. + MockBootstrapTime func() time.Duration + + // MockSOCKS5ProxyURL allows to mock Socks5ProxyURL. + MockSOCKS5ProxyURL func() *url.URL + + // MockStop allows to mock Stop. + MockStop func() +} + +func (t *Tunnel) BootstrapTime() time.Duration { + return t.MockBootstrapTime() +} + +// SOCKS5ProxyURL implements Tunnel.SOCKS5ProxyURL. +func (t *Tunnel) SOCKS5ProxyURL() *url.URL { + return t.MockSOCKS5ProxyURL() +} + +// Stop implements Tunnel.Stop. +func (t *Tunnel) Stop() { + t.MockStop() +} + +var _ tunnel.Tunnel = &Tunnel{} diff --git a/internal/tunnel/mocks/mocks_test.go b/internal/tunnel/mocks/mocks_test.go new file mode 100644 index 0000000..9509cad --- /dev/null +++ b/internal/tunnel/mocks/mocks_test.go @@ -0,0 +1,60 @@ +package mocks + +import ( + "net/url" + "testing" + "time" + + "github.com/google/go-cmp/cmp" + "github.com/ooni/probe-cli/v3/internal/atomicx" +) + +func TestTunnel(t *testing.T) { + t.Run("BootstrapTime", func(t *testing.T) { + var expected time.Duration = 114 + tun := &Tunnel{ + MockBootstrapTime: func() time.Duration { + return expected + }, + } + if tun.BootstrapTime() != expected { + t.Fatal("invalid BootstrapTime") + } + }) + + t.Run("SOCKS5ProxyURL", func(t *testing.T) { + expected := &url.URL{ + Scheme: "https", + Opaque: "", + User: &url.Userinfo{}, + Host: "www.google.com", + Path: "/robots.txt", + RawPath: "", + ForceQuery: false, + RawQuery: "", + Fragment: "", + RawFragment: "", + } + tun := &Tunnel{ + MockSOCKS5ProxyURL: func() *url.URL { + return expected + }, + } + if diff := cmp.Diff(expected.String(), tun.SOCKS5ProxyURL().String()); diff != "" { + t.Fatal(diff) + } + }) + + t.Run("Stop", func(t *testing.T) { + called := &atomicx.Int64{} + tun := &Tunnel{ + MockStop: func() { + called.Add(1) + }, + } + tun.Stop() + if called.Load() != 1 { + t.Fatal("not called") + } + }) +} diff --git a/internal/tunnel/psiphon.go b/internal/tunnel/psiphon.go index 6c3f3cd..13b4ea9 100644 --- a/internal/tunnel/psiphon.go +++ b/internal/tunnel/psiphon.go @@ -30,30 +30,38 @@ func psiphonMakeWorkingDir(config *Config) (string, error) { } // psiphonStart starts the psiphon tunnel. -func psiphonStart(ctx context.Context, config *Config) (Tunnel, error) { +func psiphonStart(ctx context.Context, config *Config) (Tunnel, DebugInfo, error) { + debugInfo := DebugInfo{ + LogFilePath: "", + Name: "psiphon", + Version: "", + } select { case <-ctx.Done(): - return nil, ctx.Err() // simplifies unit testing this code + return nil, debugInfo, ctx.Err() // simplifies unit testing this code default: } if config.TunnelDir == "" { - return nil, ErrEmptyTunnelDir + return nil, debugInfo, ErrEmptyTunnelDir } configJSON, err := config.Session.FetchPsiphonConfig(ctx) if err != nil { - return nil, err + return nil, debugInfo, err } workdir, err := psiphonMakeWorkingDir(config) if err != nil { - return nil, err + return nil, debugInfo, err } start := time.Now() tunnel, err := config.startPsiphon(ctx, configJSON, workdir) if err != nil { - return nil, err + return nil, debugInfo, err } stop := time.Now() - return &psiphonTunnel{tunnel: tunnel, bootstrapTime: stop.Sub(start)}, nil + return &psiphonTunnel{ + tunnel: tunnel, + bootstrapTime: stop.Sub(start), + }, debugInfo, nil } // Stop is an idempotent method that shuts down the tunnel diff --git a/internal/tunnel/psiphon_integration_test.go b/internal/tunnel/psiphon_integration_test.go index 2e67a7d..40e680c 100644 --- a/internal/tunnel/psiphon_integration_test.go +++ b/internal/tunnel/psiphon_integration_test.go @@ -28,7 +28,7 @@ func TestPsiphonStartStop(t *testing.T) { if err != nil { t.Fatal(err) } - tunnel, err := tunnel.Start(context.Background(), &tunnel.Config{ + tunnel, _, err := tunnel.Start(context.Background(), &tunnel.Config{ Name: "psiphon", Session: sess, TunnelDir: tunnelDir, diff --git a/internal/tunnel/psiphon_test.go b/internal/tunnel/psiphon_test.go index 42cb0e8..63e1521 100644 --- a/internal/tunnel/psiphon_test.go +++ b/internal/tunnel/psiphon_test.go @@ -13,7 +13,7 @@ func TestPsiphonWithCancelledContext(t *testing.T) { ctx, cancel := context.WithCancel(context.Background()) cancel() // immediately fail sess := &MockableSession{} - tunnel, err := psiphonStart(ctx, &Config{ + tunnel, _, err := psiphonStart(ctx, &Config{ Session: sess, TunnelDir: "testdata", }) @@ -28,7 +28,7 @@ func TestPsiphonWithCancelledContext(t *testing.T) { func TestPsiphonWithEmptyTunnelDir(t *testing.T) { ctx := context.Background() sess := &MockableSession{} - tunnel, err := psiphonStart(ctx, &Config{ + tunnel, _, err := psiphonStart(ctx, &Config{ Session: sess, TunnelDir: "", }) @@ -45,7 +45,7 @@ func TestPsiphonFetchPsiphonConfigFailure(t *testing.T) { sess := &MockableSession{ Err: expected, } - tunnel, err := psiphonStart(context.Background(), &Config{ + tunnel, _, err := psiphonStart(context.Background(), &Config{ Session: sess, TunnelDir: "testdata", }) @@ -62,7 +62,7 @@ func TestPsiphonMkdirAllFailure(t *testing.T) { sess := &MockableSession{ Result: []byte(`{}`), } - tunnel, err := psiphonStart(context.Background(), &Config{ + tunnel, _, err := psiphonStart(context.Background(), &Config{ Session: sess, TunnelDir: "testdata", testMkdirAll: func(path string, perm os.FileMode) error { @@ -82,7 +82,7 @@ func TestPsiphonStartFailure(t *testing.T) { sess := &MockableSession{ Result: []byte(`{}`), } - tunnel, err := psiphonStart(context.Background(), &Config{ + tunnel, _, err := psiphonStart(context.Background(), &Config{ Session: sess, TunnelDir: "testdata", testStartPsiphon: func(ctx context.Context, config []byte, diff --git a/internal/tunnel/tor.go b/internal/tunnel/tor.go index b8d2514..9a6c6d9 100644 --- a/internal/tunnel/tor.go +++ b/internal/tunnel/tor.go @@ -55,17 +55,23 @@ var ErrTorReturnedUnsupportedProxy = errors.New( "tor returned unsupported proxy") // torStart starts the tor tunnel. -func torStart(ctx context.Context, config *Config) (Tunnel, error) { +func torStart(ctx context.Context, config *Config) (Tunnel, DebugInfo, error) { + debugInfo := DebugInfo{ + LogFilePath: "", + Name: "tor", + Version: "", + } select { case <-ctx.Done(): - return nil, ctx.Err() // allows to write unit tests using this code + return nil, debugInfo, ctx.Err() // allows to write unit tests using this code default: } if config.TunnelDir == "" { - return nil, ErrEmptyTunnelDir + return nil, debugInfo, ErrEmptyTunnelDir } stateDir := filepath.Join(config.TunnelDir, "tor") logfile := filepath.Join(stateDir, "tor.log") + debugInfo.LogFilePath = logfile maybeCleanupTunnelDir(stateDir, logfile) extraArgs := append([]string{}, config.TorArgs...) extraArgs = append(extraArgs, "Log") @@ -74,39 +80,44 @@ func torStart(ctx context.Context, config *Config) (Tunnel, error) { extraArgs = append(extraArgs, fmt.Sprintf(`notice file %s`, logfile)) torStartConf, err := getTorStartConf(config, stateDir, extraArgs) if err != nil { - return nil, err + return nil, debugInfo, err } instance, err := config.torStart(ctx, torStartConf) if err != nil { - return nil, err + return nil, debugInfo, err } + protoInfo, err := config.torProtocolInfo(instance) + if err != nil { + return nil, debugInfo, err + } + debugInfo.Version = protoInfo.TorVersion instance.StopProcessOnClose = true start := time.Now() if err := config.torEnableNetwork(ctx, instance, true); err != nil { instance.Close() - return nil, err + return nil, debugInfo, err } stop := time.Now() // Adapted from info, err := config.torGetInfo(instance.Control, "net/listeners/socks") if err != nil { instance.Close() - return nil, err + return nil, debugInfo, err } if len(info) != 1 || info[0].Key != "net/listeners/socks" { instance.Close() - return nil, ErrTorUnableToGetSOCKSProxyAddress + return nil, debugInfo, ErrTorUnableToGetSOCKSProxyAddress } proxyAddress := info[0].Val if strings.HasPrefix(proxyAddress, "unix:") { instance.Close() - return nil, ErrTorReturnedUnsupportedProxy + return nil, debugInfo, ErrTorReturnedUnsupportedProxy } return &torTunnel{ bootstrapTime: stop.Sub(start), instance: instance, proxy: &url.URL{Scheme: "socks5", Host: proxyAddress}, - }, nil + }, debugInfo, nil } // maybeCleanupTunnelDir removes stale files inside diff --git a/internal/tunnel/tor_integration_test.go b/internal/tunnel/tor_integration_test.go index 0918d2f..aa9fd63 100644 --- a/internal/tunnel/tor_integration_test.go +++ b/internal/tunnel/tor_integration_test.go @@ -33,7 +33,7 @@ func TestTorStartStop(t *testing.T) { if err != nil { t.Fatal(err) } - tunnel, err := tunnel.Start(context.Background(), &tunnel.Config{ + tunnel, _, err := tunnel.Start(context.Background(), &tunnel.Config{ Name: "tor", Session: sess, TorBinary: torBinaryPath, diff --git a/internal/tunnel/tor_test.go b/internal/tunnel/tor_test.go index 619c200..335c994 100644 --- a/internal/tunnel/tor_test.go +++ b/internal/tunnel/tor_test.go @@ -50,7 +50,7 @@ func TestTorTunnelNonNil(t *testing.T) { func TestTorWithCancelledContext(t *testing.T) { ctx, cancel := context.WithCancel(context.Background()) cancel() // fail immediately - tun, err := torStart(ctx, &Config{ + tun, _, err := torStart(ctx, &Config{ Session: &MockableSession{}, TunnelDir: "testdata", }) @@ -64,7 +64,7 @@ func TestTorWithCancelledContext(t *testing.T) { func TestTorWithEmptyTunnelDir(t *testing.T) { ctx := context.Background() - tun, err := torStart(ctx, &Config{ + tun, _, err := torStart(ctx, &Config{ Session: &MockableSession{}, TunnelDir: "", }) @@ -78,7 +78,7 @@ func TestTorWithEmptyTunnelDir(t *testing.T) { func TestTorBinaryNotFoundFailure(t *testing.T) { ctx := context.Background() - tun, err := torStart(ctx, &Config{ + tun, _, err := torStart(ctx, &Config{ Session: &MockableSession{}, TorBinary: "/nonexistent/directory/tor", TunnelDir: "testdata", @@ -94,7 +94,7 @@ func TestTorBinaryNotFoundFailure(t *testing.T) { func TestTorStartFailure(t *testing.T) { expected := errors.New("mocked error") ctx := context.Background() - tun, err := torStart(ctx, &Config{ + tun, _, err := torStart(ctx, &Config{ Session: &MockableSession{}, TunnelDir: "testdata", testExecabsLookPath: func(name string) (string, error) { @@ -112,10 +112,10 @@ func TestTorStartFailure(t *testing.T) { } } -func TestTorEnableNetworkFailure(t *testing.T) { +func TestTorGetProtocolInfoFailure(t *testing.T) { expected := errors.New("mocked error") ctx := context.Background() - tun, err := torStart(ctx, &Config{ + tun, _, err := torStart(ctx, &Config{ Session: &MockableSession{}, TunnelDir: "testdata", testExecabsLookPath: func(name string) (string, error) { @@ -124,6 +124,33 @@ func TestTorEnableNetworkFailure(t *testing.T) { testTorStart: func(ctx context.Context, conf *tor.StartConf) (*tor.Tor, error) { return &tor.Tor{}, nil }, + testTorProtocolInfo: func(tor *tor.Tor) (*control.ProtocolInfo, error) { + return nil, expected + }, + }) + if !errors.Is(err, expected) { + t.Fatal("not the error we expected") + } + if tun != nil { + t.Fatal("expected nil tunnel here") + } +} + +func TestTorEnableNetworkFailure(t *testing.T) { + expected := errors.New("mocked error") + ctx := context.Background() + tun, _, err := torStart(ctx, &Config{ + Session: &MockableSession{}, + TunnelDir: "testdata", + testExecabsLookPath: func(name string) (string, error) { + return "/usr/local/bin/tor", nil + }, + testTorStart: func(ctx context.Context, conf *tor.StartConf) (*tor.Tor, error) { + return &tor.Tor{}, nil + }, + testTorProtocolInfo: func(tor *tor.Tor) (*control.ProtocolInfo, error) { + return &control.ProtocolInfo{}, nil + }, testTorEnableNetwork: func(ctx context.Context, tor *tor.Tor, wait bool) error { return expected }, @@ -139,7 +166,7 @@ func TestTorEnableNetworkFailure(t *testing.T) { func TestTorGetInfoFailure(t *testing.T) { expected := errors.New("mocked error") ctx := context.Background() - tun, err := torStart(ctx, &Config{ + tun, _, err := torStart(ctx, &Config{ Session: &MockableSession{}, TunnelDir: "testdata", testExecabsLookPath: func(name string) (string, error) { @@ -148,6 +175,9 @@ func TestTorGetInfoFailure(t *testing.T) { testTorStart: func(ctx context.Context, conf *tor.StartConf) (*tor.Tor, error) { return &tor.Tor{}, nil }, + testTorProtocolInfo: func(tor *tor.Tor) (*control.ProtocolInfo, error) { + return &control.ProtocolInfo{}, nil + }, testTorEnableNetwork: func(ctx context.Context, tor *tor.Tor, wait bool) error { return nil }, @@ -165,7 +195,7 @@ func TestTorGetInfoFailure(t *testing.T) { func TestTorGetInfoInvalidNumberOfKeys(t *testing.T) { ctx := context.Background() - tun, err := torStart(ctx, &Config{ + tun, _, err := torStart(ctx, &Config{ Session: &MockableSession{}, TunnelDir: "testdata", testExecabsLookPath: func(name string) (string, error) { @@ -174,6 +204,9 @@ func TestTorGetInfoInvalidNumberOfKeys(t *testing.T) { testTorStart: func(ctx context.Context, conf *tor.StartConf) (*tor.Tor, error) { return &tor.Tor{}, nil }, + testTorProtocolInfo: func(tor *tor.Tor) (*control.ProtocolInfo, error) { + return &control.ProtocolInfo{}, nil + }, testTorEnableNetwork: func(ctx context.Context, tor *tor.Tor, wait bool) error { return nil }, @@ -191,7 +224,7 @@ func TestTorGetInfoInvalidNumberOfKeys(t *testing.T) { func TestTorGetInfoInvalidKey(t *testing.T) { ctx := context.Background() - tun, err := torStart(ctx, &Config{ + tun, _, err := torStart(ctx, &Config{ Session: &MockableSession{}, TunnelDir: "testdata", testExecabsLookPath: func(name string) (string, error) { @@ -200,6 +233,9 @@ func TestTorGetInfoInvalidKey(t *testing.T) { testTorStart: func(ctx context.Context, conf *tor.StartConf) (*tor.Tor, error) { return &tor.Tor{}, nil }, + testTorProtocolInfo: func(tor *tor.Tor) (*control.ProtocolInfo, error) { + return &control.ProtocolInfo{}, nil + }, testTorEnableNetwork: func(ctx context.Context, tor *tor.Tor, wait bool) error { return nil }, @@ -217,7 +253,7 @@ func TestTorGetInfoInvalidKey(t *testing.T) { func TestTorGetInfoInvalidProxyType(t *testing.T) { ctx := context.Background() - tun, err := torStart(ctx, &Config{ + tun, _, err := torStart(ctx, &Config{ Session: &MockableSession{}, TunnelDir: "testdata", testExecabsLookPath: func(name string) (string, error) { @@ -226,6 +262,9 @@ func TestTorGetInfoInvalidProxyType(t *testing.T) { testTorStart: func(ctx context.Context, conf *tor.StartConf) (*tor.Tor, error) { return &tor.Tor{}, nil }, + testTorProtocolInfo: func(tor *tor.Tor) (*control.ProtocolInfo, error) { + return &control.ProtocolInfo{}, nil + }, testTorEnableNetwork: func(ctx context.Context, tor *tor.Tor, wait bool) error { return nil }, @@ -243,7 +282,7 @@ func TestTorGetInfoInvalidProxyType(t *testing.T) { func TestTorUnsupportedProxy(t *testing.T) { ctx := context.Background() - tun, err := torStart(ctx, &Config{ + tun, _, err := torStart(ctx, &Config{ Session: &MockableSession{}, TunnelDir: "testdata", testExecabsLookPath: func(name string) (string, error) { @@ -252,6 +291,9 @@ func TestTorUnsupportedProxy(t *testing.T) { testTorStart: func(ctx context.Context, conf *tor.StartConf) (*tor.Tor, error) { return &tor.Tor{}, nil }, + testTorProtocolInfo: func(tor *tor.Tor) (*control.ProtocolInfo, error) { + return &control.ProtocolInfo{}, nil + }, testTorEnableNetwork: func(ctx context.Context, tor *tor.Tor, wait bool) error { return nil }, diff --git a/internal/tunnel/tunnel.go b/internal/tunnel/tunnel.go index 9825c5d..4a23451 100644 --- a/internal/tunnel/tunnel.go +++ b/internal/tunnel/tunnel.go @@ -74,6 +74,22 @@ var ErrEmptyTunnelDir = errors.New("TunnelDir is empty") // is not supported by this package. var ErrUnsupportedTunnelName = errors.New("unsupported tunnel name") +// DebugInfo contains information useful to debug issues +// when starting up a given tunnel fails. +type DebugInfo struct { + // LogFilePath is the path to the log file, which MAY + // be empty in case we don't have a log file. + LogFilePath string + + // Name is the name of the tunnel and will always + // be properly set by the code. + Name string + + // Version is the tunnel version. This field MAY be + // empty if we don't know the version. + Version string +} + // Start starts a new tunnel by name or returns an error. We currently // support the following tunnels: // @@ -94,7 +110,15 @@ var ErrUnsupportedTunnelName = errors.New("unsupported tunnel name") // The "fake" tunnel is a fake tunnel that just exposes a // SOCKS5 proxy and then connects directly to server. We use // this special kind of tunnel to implement tests. -func Start(ctx context.Context, config *Config) (Tunnel, error) { +// +// The return value is a triple: +// +// 1. a valid Tunnel on success, nil on failure; +// +// 2. debugging information (both on success and failure); +// +// 3. nil on success, an error on failure. +func Start(ctx context.Context, config *Config) (Tunnel, DebugInfo, error) { switch config.Name { case "fake": return fakeStart(ctx, config) @@ -103,6 +127,7 @@ func Start(ctx context.Context, config *Config) (Tunnel, error) { case "tor": return torStart(ctx, config) default: - return nil, fmt.Errorf("%w: %s", ErrUnsupportedTunnelName, config.Name) + di := DebugInfo{} + return nil, di, fmt.Errorf("%w: %s", ErrUnsupportedTunnelName, config.Name) } } diff --git a/internal/tunnel/tunnel_test.go b/internal/tunnel/tunnel_test.go index 0bbc57d..4122ca4 100644 --- a/internal/tunnel/tunnel_test.go +++ b/internal/tunnel/tunnel_test.go @@ -10,7 +10,7 @@ import ( func TestStartNoTunnel(t *testing.T) { ctx := context.Background() - tun, err := tunnel.Start(ctx, &tunnel.Config{ + tun, _, err := tunnel.Start(ctx, &tunnel.Config{ Name: "", Session: &tunnel.MockableSession{}, }) @@ -25,7 +25,7 @@ func TestStartNoTunnel(t *testing.T) { func TestStartPsiphonWithCancelledContext(t *testing.T) { ctx, cancel := context.WithCancel(context.Background()) cancel() // fail immediately - tun, err := tunnel.Start(ctx, &tunnel.Config{ + tun, _, err := tunnel.Start(ctx, &tunnel.Config{ Name: "psiphon", Session: &tunnel.MockableSession{}, TunnelDir: "testdata", @@ -41,7 +41,7 @@ func TestStartPsiphonWithCancelledContext(t *testing.T) { func TestStartTorWithCancelledContext(t *testing.T) { ctx, cancel := context.WithCancel(context.Background()) cancel() // fail immediately - tun, err := tunnel.Start(ctx, &tunnel.Config{ + tun, _, err := tunnel.Start(ctx, &tunnel.Config{ Name: "tor", Session: &tunnel.MockableSession{}, TunnelDir: "testdata", @@ -56,7 +56,7 @@ func TestStartTorWithCancelledContext(t *testing.T) { func TestStartInvalidTunnel(t *testing.T) { ctx := context.Background() - tun, err := tunnel.Start(ctx, &tunnel.Config{ + tun, _, err := tunnel.Start(ctx, &tunnel.Config{ Name: "antani", Session: &tunnel.MockableSession{}, TunnelDir: "testdata", diff --git a/internal/tutorial/experiment/torsf/chapter04/README.md b/internal/tutorial/experiment/torsf/chapter04/README.md index ff4713c..f1d9e0d 100644 --- a/internal/tutorial/experiment/torsf/chapter04/README.md +++ b/internal/tutorial/experiment/torsf/chapter04/README.md @@ -76,11 +76,11 @@ As a first step, we create a dialer for snowflake using the `ptx` package. This dialer will allow us to create a `net.Conn`-like network connection where traffic is sent using the Snowflake pluggable transport. There are several optional fields in -`SnowflakeDialer`, but we don't need to override the default -values, so we can just use a default-initialized struct. +`SnowflakeDialer`; the `NewSnowflakeDialer` constructor will +give us a suitable configured dialer with default settings. ```Go - sfdialer := &ptx.SnowflakeDialer{} + sfdialer := ptx.NewSnowflakeDialer() ``` Let us now create a listener. The `ptx.Listener` is a listener diff --git a/internal/tutorial/experiment/torsf/chapter04/torsf.go b/internal/tutorial/experiment/torsf/chapter04/torsf.go index be9a498..5268578 100644 --- a/internal/tutorial/experiment/torsf/chapter04/torsf.go +++ b/internal/tutorial/experiment/torsf/chapter04/torsf.go @@ -141,11 +141,11 @@ func (m *Measurer) run(ctx context.Context, // `ptx` package. This dialer will allow us to create a `net.Conn`-like // network connection where traffic is sent using the Snowflake // pluggable transport. There are several optional fields in - // `SnowflakeDialer`, but we don't need to override the default - // values, so we can just use a default-initialized struct. + // `SnowflakeDialer`; the `NewSnowflakeDialer` constructor will + // give us a suitable configured dialer with default settings. // // ```Go - sfdialer := &ptx.SnowflakeDialer{} + sfdialer := ptx.NewSnowflakeDialer() // ``` // // Let us now create a listener. The `ptx.Listener` is a listener @@ -181,7 +181,7 @@ func (m *Measurer) run(ctx context.Context, // pluggable transport created by `ptl` and `sfdialer`. // // ```Go - tun, err := tunnel.Start(ctx, &tunnel.Config{ + tun, _, err := tunnel.Start(ctx, &tunnel.Config{ Name: "tor", Session: sess, TunnelDir: path.Join(sess.TempDir(), "torsf"),