Improve log output in router state machine

NHAS · Apr 27, 2024 · 9613410 · 9613410
1 parent c7769ea
commit 9613410
Show file tree

Hide file tree

Showing 19 changed files with 162 additions and 93 deletions.
diff --git a/commands/start.go b/commands/start.go
@@ -88,7 +88,7 @@ func (g *start) Check() error {
 		}
 	}
 
-	err = data.Load(config.Values.DatabaseLocation, g.clusterJoinToken)
+	err = data.Load(config.Values.DatabaseLocation, g.clusterJoinToken, false)
 	if err != nil {
 		return fmt.Errorf("cannot load database: %v", err)
 	}

diff --git a/internal/config/test_disabled_max_lifetime.json b/internal/config/test_disabled_max_lifetime.json
@@ -13,6 +13,12 @@
             "Port": "8080"
         }
     },
+    "Clustering": {
+        "ClusterState": "new",
+        "ETCDLogLevel": "error",
+        "Witness": false,
+        "TLSManagerListenURL": "https://localhost:3434"
+    },
     "Authenticators": {
         "Issuer": "192.168.121.61"
     },

diff --git a/internal/config/test_disabled_sliding_window.json b/internal/config/test_disabled_sliding_window.json
@@ -16,6 +16,12 @@
     "Authenticators": {
         "Issuer": "192.168.121.61"
     },
+    "Clustering": {
+        "ClusterState": "new",
+        "ETCDLogLevel": "error",
+        "Witness": false,
+        "TLSManagerListenURL": "https://localhost:3434"
+    },
     "Wireguard": {
         "DevName": "wg0",
         "ListenPort": 53230,

diff --git a/internal/config/test_fail_with_multiple.json b/internal/config/test_fail_with_multiple.json
@@ -16,6 +16,12 @@
     "Authenticators": {
         "Issuer": "192.168.121.61"
     },
+    "Clustering": {
+        "ClusterState": "new",
+        "ETCDLogLevel": "error",
+        "Witness": false,
+        "TLSManagerListenURL": "https://localhost:3434"
+    },
     "Wireguard": {
         "DevName": "wg45",
         "ListenPort": 53230,

diff --git a/internal/config/test_in_memory_db.json b/internal/config/test_in_memory_db.json
@@ -16,6 +16,12 @@
     "Authenticators": {
         "Issuer": "192.168.121.61"
     },
+    "Clustering": {
+        "ClusterState": "new",
+        "ETCDLogLevel": "error",
+        "Witness": false,
+        "TLSManagerListenURL": "https://localhost:3434"
+    },
     "Wireguard": {
         "DevName": "wg45",
         "ListenPort": 53230,

diff --git a/internal/config/test_mutliple_rule_definitions_and_mfa_preference.json b/internal/config/test_mutliple_rule_definitions_and_mfa_preference.json
@@ -16,6 +16,12 @@
     "Authenticators": {
         "Issuer": "192.168.121.61"
     },
+    "Clustering": {
+        "ClusterState": "new",
+        "ETCDLogLevel": "error",
+        "Witness": false,
+        "TLSManagerListenURL": "https://localhost:3434"
+    },
     "Wireguard": {
         "DevName": "wg45",
         "ListenPort": 53230,

diff --git a/internal/config/test_port_based_rules.json b/internal/config/test_port_based_rules.json
@@ -16,6 +16,12 @@
     "Authenticators": {
         "Issuer": "192.168.121.61"
     },
+    "Clustering": {
+        "ClusterState": "new",
+        "ETCDLogLevel": "error",
+        "Witness": false,
+        "TLSManagerListenURL": "https://localhost:3434"
+    },
     "Wireguard": {
         "DevName": "wg45",
         "ListenPort": 53230,

diff --git a/internal/config/test_roaming_all_routes_mfa_priority.json b/internal/config/test_roaming_all_routes_mfa_priority.json
@@ -16,6 +16,12 @@
     "Authenticators": {
         "Issuer": "192.168.121.61"
     },
+    "Clustering": {
+        "ClusterState": "new",
+        "ETCDLogLevel": "error",
+        "Witness": false,
+        "TLSManagerListenURL": "https://localhost:3434"
+    },
     "Wireguard": {
         "DevName": "wg45",
         "ListenPort": 53230,

diff --git a/internal/config/test_route_restriction_preference.json b/internal/config/test_route_restriction_preference.json
@@ -16,6 +16,12 @@
     "Authenticators": {
         "Issuer": "192.168.121.61"
     },
+    "Clustering": {
+        "ClusterState": "new",
+        "ETCDLogLevel": "error",
+        "Witness": false,
+        "TLSManagerListenURL": "https://localhost:3434"
+    },
     "Wireguard": {
         "DevName": "wg45",
         "ListenPort": 53230,

diff --git a/internal/data/devices.go b/internal/data/devices.go
@@ -25,6 +25,16 @@ type Device struct {
 	Authorised   time.Time
 }
 
+func (d Device) String() string {
+
+	authorised := "no"
+	if !d.Authorised.Equal(time.Time{}) {
+		authorised = d.Authorised.Format(time.DateTime)
+	}
+
+	return fmt.Sprintf("device[%s:%s][active: %t, attempts: %d, authorised: %s]", d.Username, d.Address, d.Active, d.Attempts, authorised)
+}
+
 func UpdateDeviceEndpoint(address string, endpoint *net.UDPAddr) error {
 
 	realKey, err := etcd.Get(context.Background(), "deviceref-"+address)
@@ -36,10 +46,7 @@ func UpdateDeviceEndpoint(address string, endpoint *net.UDPAddr) error {
 		return errors.New("device was not found")
 	}
 
-	var realDeviceAddr string
-	json.Unmarshal(realKey.Kvs[0].Value, &realDeviceAddr)
-
-	return doSafeUpdate(context.Background(), realDeviceAddr, func(gr *clientv3.GetResponse) (string, error) {
+	return doSafeUpdate(context.Background(), string(realKey.Kvs[0].Value), func(gr *clientv3.GetResponse) (string, error) {
 		if len(gr.Kvs) != 1 {
 			return "", errors.New("user device has multiple keys")
 		}

diff --git a/internal/data/events.go b/internal/data/events.go
@@ -111,7 +111,7 @@ func RegisterEventListener[T any](path string, isPrefix bool, f func(key string,
 
 				go func(key []byte) {
 					if err := f(string(key), currentValue, previousValue, state); err != nil {
-						log.Println("applying event failed: ", currentValue, "err:", err)
+						log.Println("applying event failed: ", state, currentValue, "err:", err)
 						err = RaiseError(GetServerID(), err, value)
 						if err != nil {
 							log.Println("failed to raise error with cluster: ", err)
@@ -180,6 +180,10 @@ func checkClusterHealth() {
 			notifyHealthy()
 
 		case <-time.After(1 * time.Second):
+			if etcdServer == nil {
+				return
+			}
+
 			leader := etcdServer.Server.Leader()
 			if leader == 0 {
 				notifyClusterHealthListeners("electing")

diff --git a/internal/data/init.go b/internal/data/init.go
@@ -48,7 +48,7 @@ func parseUrls(values ...string) []url.URL {
 	return urls
 }
 
-func Load(path, joinToken string) error {
+func Load(path, joinToken string, testing bool) error {
 
 	doMigration := true
 	if _, err := os.Stat(path); errors.Is(err, os.ErrNotExist) {
@@ -84,33 +84,35 @@ func Load(path, joinToken string) error {
 
 	var err error
 
-	if joinToken == "" {
-		TLSManager, err = manager.New(config.Values.Clustering.TLSManagerStorage, config.Values.Clustering.TLSManagerListenURL)
-		if err != nil {
-			return fmt.Errorf("tls manager: %s", err)
-		}
-	} else {
-
-		if config.Values.Clustering.TLSManagerStorage == "" {
-			config.Values.Clustering.TLSManagerStorage = "certificates"
-		}
+	if TLSManager == nil {
+		if joinToken == "" {
+			TLSManager, err = manager.New(config.Values.Clustering.TLSManagerStorage, config.Values.Clustering.TLSManagerListenURL)
+			if err != nil {
+				return fmt.Errorf("tls manager: %s", err)
+			}
+		} else {
 
-		TLSManager, err = manager.Join(joinToken, config.Values.Clustering.TLSManagerStorage, map[string]func(name string, data string){
-			"config.json": func(name, data string) {
-				err := os.WriteFile("config.json", []byte(data), 0600)
-				if err != nil {
-					log.Fatal("failed to create config.json from other cluster members config: ", err)
-				}
+			if config.Values.Clustering.TLSManagerStorage == "" {
+				config.Values.Clustering.TLSManagerStorage = "certificates"
+			}
 
-				log.Println("got additional, loading config file")
-				err = config.Load("config.json")
-				if err != nil {
-					log.Fatal("config supplied by other cluster member was invalid (potential version issues?): ", err)
-				}
-			},
-		})
-		if err != nil {
-			return err
+			TLSManager, err = manager.Join(joinToken, config.Values.Clustering.TLSManagerStorage, map[string]func(name string, data string){
+				"config.json": func(name, data string) {
+					err := os.WriteFile("config.json", []byte(data), 0600)
+					if err != nil {
+						log.Fatal("failed to create config.json from other cluster members config: ", err)
+					}
+
+					log.Println("got additional, loading config file")
+					err = config.Load("config.json")
+					if err != nil {
+						log.Fatal("config supplied by other cluster member was invalid (potential version issues?): ", err)
+					}
+				},
+			})
+			if err != nil {
+				return err
+			}
 		}
 	}
 	part, err := generateRandomBytes(10)
@@ -121,8 +123,11 @@ func Load(path, joinToken string) error {
 
 	cfg := embed.NewConfig()
 	cfg.Name = config.Values.Clustering.Name
+	if testing {
+		cfg.Name += part
+	}
 	cfg.ClusterState = config.Values.Clustering.ClusterState
-	cfg.InitialClusterToken = "wag-test"
+	cfg.InitialClusterToken = "wag"
 	cfg.LogLevel = config.Values.Clustering.ETCDLogLevel
 	cfg.ListenPeerUrls = parseUrls(config.Values.Clustering.ListenAddresses...)
 	cfg.ListenClientUrls = parseUrls(etcdUnixSocket)
@@ -149,7 +154,7 @@ func Load(path, joinToken string) error {
 
 	cfg.InitialCluster = cfg.InitialCluster[:len(cfg.InitialCluster)-1]
 
-	cfg.Dir = filepath.Join(config.Values.Clustering.DatabaseLocation, config.Values.Clustering.Name+".wag-node.etcd")
+	cfg.Dir = filepath.Join(config.Values.Clustering.DatabaseLocation, cfg.Name+".wag-node.etcd")
 	etcdServer, err = embed.StartEtcd(cfg)
 	if err != nil {
 		return fmt.Errorf("error starting etcd: %s", err)
@@ -454,8 +459,11 @@ func migrateFromSql(database *sql.DB) error {
 
 func TearDown() {
 	if etcdServer != nil {
-		log.Println("Tearing down server")
+		etcd.Close()
 		etcdServer.Close()
+
+		etcd = nil
+		etcdServer = nil
 	}
 }
 

diff --git a/internal/data/user.go b/internal/data/user.go
@@ -249,12 +249,7 @@ func DeleteUser(username string) error {
 		return err
 	}
 
-	_, err = etcd.Delete(context.Background(), "devices-"+username+"-", clientv3.WithPrefix())
-	if err != nil {
-		return err
-	}
-
-	return err
+	return DeleteDevices(username)
 }
 
 func GetUserData(username string) (u UserModel, err error) {

diff --git a/internal/router/bpf.go b/internal/router/bpf.go
@@ -527,7 +527,7 @@ func RemoveUser(username string) error {
 	for address, publicKey := range usersToAddresses[username] {
 		err = _removePeer(publicKey, address)
 		if err != nil {
-			log.Println("unable to remove peer: ", err)
+			log.Println("unable to remove peer: ", address, err)
 		}
 	}
 

diff --git a/internal/router/fwentry.go b/internal/router/fwentry.go
@@ -37,7 +37,7 @@ func (d fwentry) Bytes() []byte {
 
 func (d *fwentry) Unpack(b []byte) error {
 	if len(b) != 40 {
-		return errors.New("too short")
+		return errors.New("firewall entry is too short")
 	}
 
 	d.sessionExpiry = binary.LittleEndian.Uint64(b[:8])