c/ooni-probe-cli
Watch
1
0
Fork
You've already forked ooni-probe-cli
 0
Code Issues Pull requests Projects Releases Packages Wiki Activity

feat(torsf): collect tor logs, select rendezvous method, count bytes (#683)

Browse source 
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.)
This commit is contained in:
Simone Basso 2022-02-07 17:05:36 +01:00 • committed by GitHub
commit 85664f1e31
No known key found for this signature in database
GPG key ID: 4AEE18F83AFDEB23
40 changed files with 1124 additions and 308 deletions
Download patch file Download diff file Expand all files Collapse all files

173
internal/engine/experiment/torsf/torsf.go
View file

@ -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
}