Merge pull request #687 from adam-p/clientlib-notices

clientlib fixes: StartTunnel re-entry, early stderr notices, clearing notice writer

(cherry picked from commit a9632594e9b0242bd586df8166923310e544b459)

ClientLibrary/clientlib/clientlib.go

@@ -140,63 +140,9 @@ func StartTunnel(
 	if !started.CompareAndSwap(false, true) {
 		return nil, errMultipleStart
 	}
-
-	config, err := psiphon.LoadConfig(configJSON)
-	if err != nil {
-		return nil, errors.TraceMsg(err, "failed to load config file")
-	}
-
-	// Use params.DataRootDirectory to set related config values.
-	if params.DataRootDirectory != nil {
-		config.DataRootDirectory = *params.DataRootDirectory
-
-		// Migrate old fields
-		config.MigrateDataStoreDirectory = *params.DataRootDirectory
-		config.MigrateObfuscatedServerListDownloadDirectory = *params.DataRootDirectory
-		config.MigrateRemoteServerListDownloadFilename = filepath.Join(*params.DataRootDirectory, "server_list_compressed")
-	}
-
-	if params.NetworkID != nil {
-		config.NetworkID = *params.NetworkID
-	}
-
-	if params.ClientPlatform != nil {
-		config.ClientPlatform = *params.ClientPlatform
-	} // else use the value in config
-
-	if params.EstablishTunnelTimeoutSeconds != nil {
-		config.EstablishTunnelTimeoutSeconds = params.EstablishTunnelTimeoutSeconds
-	} // else use the value in config
-
-	if config.UseNoticeFiles == nil && config.EmitDiagnosticNotices && params.EmitDiagnosticNoticesToFiles {
-		config.UseNoticeFiles = &psiphon.UseNoticeFiles{
-			RotatingFileSize:      0,
-			RotatingSyncFrequency: 0,
-		}
-	} // else use the value in the config
-
-	if params.DisableLocalSocksProxy != nil {
-		config.DisableLocalSocksProxy = *params.DisableLocalSocksProxy
-	} // else use the value in the config
-
-	if params.DisableLocalHTTPProxy != nil {
-		config.DisableLocalHTTPProxy = *params.DisableLocalHTTPProxy
-	} // else use the value in the config
-
-	// config.Commit must be called before calling config.SetParameters
-	// or attempting to connect.
-	err = config.Commit(true)
-	if err != nil {
-		return nil, errors.TraceMsg(err, "config.Commit failed")
-	}
-
-	// If supplied, apply the parameters delta
-	if len(paramsDelta) > 0 {
-		err = config.SetParameters("", false, paramsDelta)
-		if err != nil {
-			return nil, errors.TraceMsg(err, fmt.Sprintf("SetParameters failed for delta: %v", paramsDelta))
-		}
-	}
+	// There _must_ not be an early return between here and where tunnel.stop is deferred,
+	// otherwise `started` will not get set back to false and we will be unable to call
+	// StartTunnel again.
 
 	// Will be closed when the tunnel has successfully connected
 	connectedSignal := make(chan struct{})
@@ -206,7 +152,8 @@ func StartTunnel(
 	// Create the tunnel object
 	tunnel := new(PsiphonTunnel)
 
-	// Set up notice handling
+	// Set up notice handling. It is important to do this before config operations, as
+	// otherwise they will write notices to stderr.
 	psiphon.SetNoticeWriter(psiphon.NewNoticeReceiver(
 		func(notice []byte) {
 			var event NoticeEvent
@@ -247,11 +194,6 @@ func StartTunnel(
 			}
 		}))
 
-	err = psiphon.OpenDataStore(config)
-	if err != nil {
-		return nil, errors.TraceMsg(err, "failed to open data store")
-	}
-
 	// Create a cancelable context that will be used for stopping the tunnel
 	tunnelCtx, cancelTunnelCtx := context.WithCancel(ctx)
 
@@ -265,8 +207,12 @@ func StartTunnel(
 		cancelTunnelCtx()
 		tunnel.embeddedServerListWaitGroup.Wait()
 		tunnel.controllerWaitGroup.Wait()
+		// This is safe to call even if the data store hasn't been opened
 		psiphon.CloseDataStore()
 		started.Store(false)
+		// Clear our notice receiver, as it is no longer needed and we should let it be
+		// garbage-collected.
+		psiphon.SetNoticeWriter(io.Discard)
 	}
 
 	defer func() {
@@ -274,6 +220,69 @@ func StartTunnel(
 			tunnel.stop()
 		}
 	}()
+	// We have now set up our on-error cleanup and it is safe to have early error returns.
+
+	config, err := psiphon.LoadConfig(configJSON)
+	if err != nil {
+		return nil, errors.TraceMsg(err, "failed to load config file")
+	}
+
+	// Use params.DataRootDirectory to set related config values.
+	if params.DataRootDirectory != nil {
+		config.DataRootDirectory = *params.DataRootDirectory
+
+		// Migrate old fields
+		config.MigrateDataStoreDirectory = *params.DataRootDirectory
+		config.MigrateObfuscatedServerListDownloadDirectory = *params.DataRootDirectory
+		config.MigrateRemoteServerListDownloadFilename = filepath.Join(*params.DataRootDirectory, "server_list_compressed")
+	}
+
+	if params.NetworkID != nil {
+		config.NetworkID = *params.NetworkID
+	}
+
+	if params.ClientPlatform != nil {
+		config.ClientPlatform = *params.ClientPlatform
+	} // else use the value in config
+
+	if params.EstablishTunnelTimeoutSeconds != nil {
+		config.EstablishTunnelTimeoutSeconds = params.EstablishTunnelTimeoutSeconds
+	} // else use the value in config
+
+	if config.UseNoticeFiles == nil && config.EmitDiagnosticNotices && params.EmitDiagnosticNoticesToFiles {
+		config.UseNoticeFiles = &psiphon.UseNoticeFiles{
+			RotatingFileSize:      0,
+			RotatingSyncFrequency: 0,
+		}
+	} // else use the value in the config
+
+	if params.DisableLocalSocksProxy != nil {
+		config.DisableLocalSocksProxy = *params.DisableLocalSocksProxy
+	} // else use the value in the config
+
+	if params.DisableLocalHTTPProxy != nil {
+		config.DisableLocalHTTPProxy = *params.DisableLocalHTTPProxy
+	} // else use the value in the config
+
+	// config.Commit must be called before calling config.SetParameters
+	// or attempting to connect.
+	err = config.Commit(true)
+	if err != nil {
+		return nil, errors.TraceMsg(err, "config.Commit failed")
+	}
+
+	// If supplied, apply the parameters delta
+	if len(paramsDelta) > 0 {
+		err = config.SetParameters("", false, paramsDelta)
+		if err != nil {
+			return nil, errors.TraceMsg(err, fmt.Sprintf("SetParameters failed for delta: %v", paramsDelta))
+		}
+	}
+
+	err = psiphon.OpenDataStore(config)
+	if err != nil {
+		return nil, errors.TraceMsg(err, "failed to open data store")
+	}
 
 	// If specified, the embedded server list is loaded and stored. When there
 	// are no server candidates at all, we wait for this import to complete
@@ -374,10 +383,6 @@ func (tunnel *PsiphonTunnel) Stop() {
 	tunnel.stop()
 	tunnel.stop = nil
 	tunnel.controllerDial = nil
-
-	// Clear our notice receiver, as it is no longer needed and we should let it be
-	// garbage-collected.
-	psiphon.SetNoticeWriter(io.Discard)
 }
 
 // Dial connects to the specified address through the Psiphon tunnel.

ClientLibrary/clientlib/clientlib_test.go

@@ -22,26 +22,52 @@ package clientlib
 import (
 	"context"
 	"encoding/json"
+	"errors"
 	"os"
+	"strings"
 	"testing"
 	"time"
+
+	"github.com/Psiphon-Labs/psiphon-tunnel-core/psiphon"
 )
 
+func setupConfig(t *testing.T, disableFetcher bool) []byte {
+	configJSON, err := os.ReadFile("../../psiphon/controller_test.config")
+	if err != nil {
+		// What to do if config file is not present?
+		t.Skipf("error loading configuration file: %s", err)
+	}
+
+	var config map[string]interface{}
+	err = json.Unmarshal(configJSON, &config)
+	if err != nil {
+		t.Fatalf("json.Unmarshal failed: %v", err)
+	}
+
+	if disableFetcher {
+		config["DisableRemoteServerListFetcher"] = true
+	}
+
+	configJSON, err = json.Marshal(config)
+	if err != nil {
+		t.Fatalf("json.Marshal failed: %v", err)
+	}
+
+	return configJSON
+}
+
 func TestStartTunnel(t *testing.T) {
 	// TODO: More comprehensive tests. This is only a smoke test.
 
+	configJSON := setupConfig(t, false)
+	configJSONNoFetcher := setupConfig(t, true)
+
 	clientPlatform := "clientlib_test.go"
 	networkID := "UNKNOWN"
 	timeout := 60
 	quickTimeout := 1
 	trueVal := true
 
-	configJSON, err := os.ReadFile("../../psiphon/controller_test.config")
-	if err != nil {
-		// Skip, don't fail, if config file is not present
-		t.Skipf("error loading configuration file: %s", err)
-	}
-
 	// Initialize a fresh datastore and create a modified config which cannot
 	// connect without known servers, to be used in timeout cases.
 
@@ -51,17 +77,11 @@ func TestStartTunnel(t *testing.T) {
 	}
 	defer os.RemoveAll(testDataDirName)
 
-	var config map[string]interface{}
-	err = json.Unmarshal(configJSON, &config)
-	if err != nil {
-		t.Fatalf("json.Unmarshal failed: %v", err)
+	paramsDeltaErr := func(err error) bool {
+		return strings.Contains(err.Error(), "SetParameters failed for delta")
 	}
-
-	config["DisableRemoteServerListFetcher"] = true
-
-	configJSONNoFetcher, err := json.Marshal(config)
-	if err != nil {
-		t.Fatalf("json.Marshal failed: %v", err)
+	timeoutErr := func(err error) bool {
+		return errors.Is(err, ErrTimeout)
 	}
 
 	type args struct {
@@ -76,7 +96,7 @@ func TestStartTunnel(t *testing.T) {
 		name        string
 		args        args
 		wantTunnel  bool
-		expectedErr error
+		expectedErr func(error) bool
 	}{
 		{
 			name: "Failure: context timeout",
@@ -94,7 +114,7 @@ func TestStartTunnel(t *testing.T) {
 				noticeReceiver: nil,
 			},
 			wantTunnel:  false,
-			expectedErr: ErrTimeout,
+			expectedErr: timeoutErr,
 		},
 		{
 			name: "Failure: config timeout",
@@ -112,7 +132,7 @@ func TestStartTunnel(t *testing.T) {
 				noticeReceiver: nil,
 			},
 			wantTunnel:  false,
-			expectedErr: ErrTimeout,
+			expectedErr: timeoutErr,
 		},
 		{
 			name: "Success: simple",
@@ -190,6 +210,42 @@ func TestStartTunnel(t *testing.T) {
 			wantTunnel:  true,
 			expectedErr: nil,
 		},
+		{
+			name: "Success: good ParametersDelta",
+			args: args{
+				ctxTimeout:              0,
+				configJSON:              configJSON,
+				embeddedServerEntryList: "",
+				params: Parameters{
+					DataRootDirectory:             &testDataDirName,
+					ClientPlatform:                &clientPlatform,
+					NetworkID:                     &networkID,
+					EstablishTunnelTimeoutSeconds: &timeout,
+				},
+				paramsDelta:    ParametersDelta{"NetworkLatencyMultiplierMin": 1},
+				noticeReceiver: nil,
+			},
+			wantTunnel:  true,
+			expectedErr: nil,
+		},
+		{
+			name: "Failure: bad ParametersDelta",
+			args: args{
+				ctxTimeout:              0,
+				configJSON:              configJSON,
+				embeddedServerEntryList: "",
+				params: Parameters{
+					DataRootDirectory:             &testDataDirName,
+					ClientPlatform:                &clientPlatform,
+					NetworkID:                     &networkID,
+					EstablishTunnelTimeoutSeconds: &timeout,
+				},
+				paramsDelta:    ParametersDelta{"invalidParam": 1},
+				noticeReceiver: nil,
+			},
+			wantTunnel:  false,
+			expectedErr: paramsDeltaErr,
+		},
 	}
 	for _, tt := range tests {
 		t.Run(tt.name, func(t *testing.T) {
@@ -222,8 +278,16 @@ func TestStartTunnel(t *testing.T) {
 				t.Errorf("StartTunnel() gotTunnel = %v, wantTunnel %v", err, tt.wantTunnel)
 			}
 
-			if err != tt.expectedErr {
-				t.Fatalf("StartTunnel() error = %v, expectedErr %v", err, tt.expectedErr)
+			if tt.expectedErr == nil {
+				if err != nil {
+					t.Fatalf("StartTunnel() returned unexpected error: %v", err)
+				}
+			} else if !tt.expectedErr(err) {
+				t.Fatalf("StartTunnel() error: %v", err)
+				return
+			}
+
+			if err != nil {
 				return
 			}
 
@@ -255,12 +319,7 @@ func TestStartTunnel(t *testing.T) {
 }
 
 func TestMultipleStartTunnel(t *testing.T) {
-	configJSON, err := os.ReadFile("../../psiphon/controller_test.config")
-	if err != nil {
-		// What to do if config file is not present?
-		t.Skipf("error loading configuration file: %s", err)
-	}
-
+	configJSON := setupConfig(t, false)
 	testDataDirName, err := os.MkdirTemp("", "psiphon-clientlib-test")
 	if err != nil {
 		t.Fatalf("ioutil.TempDir failed: %v", err)
@@ -313,12 +372,8 @@ func TestMultipleStartTunnel(t *testing.T) {
 }
 
 func TestPsiphonTunnel_Dial(t *testing.T) {
+	configJSON := setupConfig(t, false)
 	trueVal := true
-	configJSON, err := os.ReadFile("../../psiphon/controller_test.config")
-	if err != nil {
-		// Skip, don't fail, if config file is not present
-		t.Skipf("error loading configuration file: %s", err)
-	}
 
 	testDataDirName, err := os.MkdirTemp("", "psiphon-clientlib-test")
 	if err != nil {
@@ -330,9 +385,10 @@ func TestPsiphonTunnel_Dial(t *testing.T) {
 		remoteAddr string
 	}
 	tests := []struct {
-		name    string
-		args    args
-		wantErr bool
+		name          string
+		args          args
+		wantErr       bool
+		tunnelStopped bool
 	}{
 		{
 			name:    "Success: example.com",
@@ -344,6 +400,12 @@ func TestPsiphonTunnel_Dial(t *testing.T) {
 			args:    args{remoteAddr: "example.com:99999"},
 			wantErr: true,
 		},
+		{
+			name:          "Failure: tunnel not started",
+			args:          args{remoteAddr: "example.com:443"},
+			wantErr:       true,
+			tunnelStopped: true,
+		},
 	}
 	for _, tt := range tests {
 		t.Run(tt.name, func(t *testing.T) {
@@ -365,6 +427,10 @@ func TestPsiphonTunnel_Dial(t *testing.T) {
 			}
 			defer tunnel.Stop()
 
+			if tt.tunnelStopped {
+				tunnel.Stop()
+			}
+
 			conn, err := tunnel.Dial(tt.args.remoteAddr)
 			if (err != nil) != tt.wantErr {
 				t.Fatalf("PsiphonTunnel.Dial() error = %v, wantErr %v", err, tt.wantErr)
@@ -377,3 +443,79 @@ func TestPsiphonTunnel_Dial(t *testing.T) {
 		})
 	}
 }
+
+// We had a problem where config-related notices were being printed to stderr before we
+// set the NoticeWriter. We want to make sure that no longer happens.
+func TestStartTunnelNoOutput(t *testing.T) {
+	// Before starting the tunnel, set up a notice receiver. If it receives anything at
+	// all, that means that it would have been printed to stderr.
+	psiphon.SetNoticeWriter(psiphon.NewNoticeReceiver(
+		func(notice []byte) {
+			t.Fatalf("Received notice: %v", string(notice))
+		}))
+
+	configJSON := setupConfig(t, false)
+
+	testDataDirName, err := os.MkdirTemp("", "psiphon-clientlib-test")
+	if err != nil {
+		t.Fatalf("ioutil.TempDir failed: %v", err)
+	}
+	defer os.RemoveAll(testDataDirName)
+
+	ctx := context.Background()
+
+	tunnel, err := StartTunnel(
+		ctx,
+		configJSON,
+		"",
+		Parameters{DataRootDirectory: &testDataDirName},
+		nil,
+		nil)
+
+	if err != nil {
+		t.Fatalf("StartTunnel() error = %v", err)
+	}
+	tunnel.Stop()
+}
+
+// We had a problem where a very early error could result in `started` being set to true
+// and not be set back to false, preventing StartTunnel from being re-callable.
+func TestStartTunnelReentry(t *testing.T) {
+	testDataDirName, err := os.MkdirTemp("", "psiphon-clientlib-test")
+	if err != nil {
+		t.Fatalf("ioutil.TempDir failed: %v", err)
+	}
+	defer os.RemoveAll(testDataDirName)
+
+	configJSON := []byte("BAD CONFIG JSON")
+
+	ctx := context.Background()
+
+	_, err = StartTunnel(
+		ctx,
+		configJSON,
+		"",
+		Parameters{DataRootDirectory: &testDataDirName},
+		nil,
+		nil)
+
+	if err == nil {
+		t.Fatalf("expected config error")
+	}
+
+	// Call again with a good config. Should work.
+	configJSON = setupConfig(t, false)
+
+	tunnel, err := StartTunnel(
+		ctx,
+		configJSON,
+		"",
+		Parameters{DataRootDirectory: &testDataDirName},
+		nil,
+		nil)
+
+	if err != nil {
+		t.Fatalf("StartTunnel() error = %v", err)
+	}
+	tunnel.Stop()
+}