lib/model: Forget pending folders no longer announced in ClusterConfig (fixes #5187) (#7205)

* lib/db: Add ExpirePendingFolders().

Use-case is to drop any no-longer-pending folders for a specific
device when parsing its ClusterConfig message where previously offered
folders are not mentioned any more.

The timestamp in ObservedFolder is stored with only second precision,
so round to seconds here as well.  This allows calling the function
within the same second of adding or updating entries.

* lib/model: Weed out pending folders when receiving ClusterConfig.

Filter the entries by timestamp, which must be newer than or equal to
the reception time of the ClusterConfig.  For just mentioned ones,
this assumption will hold as AddOrUpdatePendingFolder() updates the
timestamp.

* lib/model, gui: Notify when one or more pending folders expired.

Introduce new event type FolderOfferCancelled and use it to trigger a
complete refreshCluster() cycle.  Listing individual entries would be
much more code and probably just as much work to answer the API
request.

* lib/model: Add comment and rename ExpirePendingFolders().

* lib/events: Rename FolderOfferCancelled to ClusterPendingChanged.

* lib/model: Reuse ClusterPendingChanged event for cleanPending()

Changing the config does not necessarily mean that the
/resut/cluster/pending endpoints need to be refreshed, but only if
something was actually removed.  Detect this and indicate it through
the ClusterPendingChanged event, which is already hooked up to requery
respective endpoints within the GUI.

No more need for a separate refreshCluster() in reaction to
ConfigSaved event or calling refreshConfig().

* lib/model: Gofmt.

* lib/db: Warn instead of info log for failed removal.

* gui: Fix pending notifications not loading on GUI start.

* lib/db: Use short device ID in log message.

* lib/db: Return list of expired folder IDs after deleting them.

* lib/model: Refactor Pending...Changed events.

* lib/model: Adjust format of removed pending folders enumeration.

Use an array of objects with device / folder ID properties, matching
the other places where it's used.

* lib/db: Drop invalid entries in RemovePendingFoldersBeforeTime().

* lib/model: Gofmt.

My local gofmt did not complain here, strangely...

* gui: Handle PendingDevicesChanged event.

Even though it currently only holds one device at a time, wrap the
contents in an array under the "added" property name.

* lib/model: Fix null values in PendingFoldersChanged removed member.

* gui: Handle PendingFoldersChanged event.

* lib/model: Simplify construction of expiredPendingList.

* lib/model: Reduce code duplication in cleanPending().

Use goto and a label for the common parts of calling the DB removal
function and building the event data part.

* lib/events, gui: Mark ...Rejected events deprecated.

Extend comments explaining the conditions when the replacement event
types are emitted.

* lib/model: Wrap removed devices in array of objects as well.

* lib/db: Use iter.Value() instead of needless db.Get(iter.Key())

* lib/db: Add comment explaining RemovePendingFoldersBeforeTime().

* lib/model: Rename fields folderID and deviceID in event data.

* lib/db: Only list actually expired IDs as removed.

Skip entries where Delete() failed as well as invalid entries that got
removed automatically.

* lib/model: Gofmt

gui/default/syncthing/core/eventService.js

@@ -60,12 +60,14 @@ angular.module('syncthing.core')
             DEVICE_CONNECTED: 'DeviceConnected',   // Generated each time a connection to a device has been established
             DEVICE_DISCONNECTED: 'DeviceDisconnected',   // Generated each time a connection to a device has been terminated
             DEVICE_DISCOVERED: 'DeviceDiscovered',   // Emitted when a new device is discovered using local discovery
-            DEVICE_REJECTED: 'DeviceRejected',   // Emitted when there is a connection from a device we are not configured to talk to
+            DEVICE_REJECTED: 'DeviceRejected',   // DEPRECATED: Emitted when there is a connection from a device we are not configured to talk to
+            PENDING_DEVICES_CHANGED: 'PendingDevicesChanged',   // Emitted when pending devices were added / updated (connection from unknown ID) or removed (device is ignored or added)
             DEVICE_PAUSED: 'DevicePaused',   // Emitted when a device has been paused
             DEVICE_RESUMED: 'DeviceResumed',   // Emitted when a device has been resumed
             DOWNLOAD_PROGRESS: 'DownloadProgress',   // Emitted during file downloads for each folder for each file
             FOLDER_COMPLETION: 'FolderCompletion',   //Emitted when the local or remote contents for a folder changes
-            FOLDER_REJECTED: 'FolderRejected',   // Emitted when a device sends index information for a folder we do not have, or have but do not share with the device in question
+            FOLDER_REJECTED: 'FolderRejected',   // DEPRECATED: Emitted when a device sends index information for a folder we do not have, or have but do not share with the device in question
+            PENDING_FOLDERS_CHANGED: 'PendingFoldersChanged',   // Emitted when pending folders were added / updated (offered by some device, but not shared to them) or removed (folder ignored or added or no longer offered from the remote device)
             FOLDER_SUMMARY: 'FolderSummary',   // Emitted when folder contents have changed locally
             ITEM_FINISHED: 'ItemFinished',   // Generated when Syncthing ends synchronizing a file to a newer version
             ITEM_STARTED: 'ItemStarted',   // Generated when Syncthing begins synchronizing a file to a newer version

gui/default/syncthing/core/syncthingController.js

@@ -122,6 +122,7 @@ angular.module('syncthing.core')
             refreshSystem();
             refreshDiscoveryCache();
             refreshConfig();
+            refreshCluster();
             refreshConnectionStats();
             refreshDeviceStats();
             refreshFolderStats();
@@ -244,32 +245,69 @@ angular.module('syncthing.core')
             }
         });
 
-        $scope.$on(Events.DEVICE_REJECTED, function (event, arg) {
-            var pendingDevice = {
-                time: arg.time,
-                name: arg.data.name,
-                address: arg.data.address
-            };
-            console.log("rejected device:", arg.data.device, pendingDevice);
+        $scope.$on(Events.PENDING_DEVICES_CHANGED, function (event, arg) {
+            if (!(arg.data.added || arg.data.removed)) {
+                // Not enough information to update in place, just refresh it completely
+                refreshCluster();
+                return;
+            }
+
+            if (arg.data.added) {
+                arg.data.added.forEach(function (rejected) {
+                    var pendingDevice = {
+                        time: arg.time,
+                        name: rejected.name,
+                        address: rejected.address
+                    };
+                    console.log("rejected device:", rejected.deviceID, pendingDevice);
+                    $scope.pendingDevices[rejected.deviceID] = pendingDevice;
+                });
+            }
 
-            $scope.pendingDevices[arg.data.device] = pendingDevice;
+            if (arg.data.removed) {
+                arg.data.removed.forEach(function (dev) {
+                    console.log("no longer pending device:", dev.deviceID);
+                    delete $scope.pendingDevices[dev.deviceID];
+                });
+            }
         });
 
-        $scope.$on(Events.FOLDER_REJECTED, function (event, arg) {
-            var offeringDevice = {
-                time: arg.time,
-                label: arg.data.folderLabel
-            };
-            console.log("rejected folder", arg.data.folder, "from device:", arg.data.device, offeringDevice);
+        $scope.$on(Events.PENDING_FOLDERS_CHANGED, function (event, arg) {
+            if (!(arg.data.added || arg.data.removed)) {
+                // Not enough information to update in place, just refresh it completely
+                refreshCluster();
+                return;
+            }
 
-            var pendingFolder = $scope.pendingFolders[arg.data.folder];
-            if (pendingFolder === undefined) {
-                pendingFolder = {
-                    offeredBy: {}
-                };
+            if (arg.data.added) {
+                arg.data.added.forEach(function (rejected) {
+                    var offeringDevice = {
+                        time: arg.time,
+                        label: rejected.folderLabel
+                    };
+                    console.log("rejected folder", rejected.folderID, "from device:", rejected.deviceID, offeringDevice);
+
+                    var pendingFolder = $scope.pendingFolders[rejected.folderID];
+                    if (pendingFolder === undefined) {
+                        pendingFolder = {
+                            offeredBy: {}
+                        };
+                    }
+                    pendingFolder.offeredBy[rejected.deviceID] = offeringDevice;
+                    $scope.pendingFolders[rejected.folderID] = pendingFolder;
+                });
+            }
+
+            if (arg.data.removed) {
+                arg.data.removed.forEach(function (folderDev) {
+                    console.log("no longer pending folder", folderDev.folderID, "from device:", folderDev.deviceID);
+                    if (folderDev.deviceID === undefined) {
+                        delete $scope.pendingFolders[folderDev.folderID];
+                    } else if ($scope.pendingFolders[folderDev.folderID]) {
+                        delete $scope.pendingFolders[folderDev.folderID].offeredBy[folderDev.deviceID];
+                    }
+                });
             }
-            pendingFolder.offeredBy[arg.data.device] = offeringDevice;
-            $scope.pendingFolders[arg.data.folder] = pendingFolder;
         });
 
         $scope.$on('ConfigLoaded', function () {
@@ -421,7 +459,6 @@ angular.module('syncthing.core')
                 });
             });
 
-            refreshCluster();
             refreshNoAuthWarning();
             setDefaultTheme();
 

lib/db/observed.go

@@ -111,6 +111,42 @@ func (db *Lowlevel) RemovePendingFolder(id string) {
 	}
 }
 
+// RemovePendingFoldersBeforeTime removes entries for a specific device which are older
+// than a given timestamp or invalid.  It returns only the valid removed folder IDs.
+func (db *Lowlevel) RemovePendingFoldersBeforeTime(device protocol.DeviceID, oldest time.Time) ([]string, error) {
+	prefixKey, err := db.keyer.GeneratePendingFolderKey(nil, device[:], nil)
+	if err != nil {
+		return nil, err
+	}
+	iter, err := db.NewPrefixIterator(prefixKey)
+	if err != nil {
+		return nil, err
+	}
+	defer iter.Release()
+	oldest = oldest.Round(time.Second)
+	var res []string
+	for iter.Next() {
+		var of ObservedFolder
+		var folderID string
+		if err = of.Unmarshal(iter.Value()); err != nil {
+			l.Infof("Invalid pending folder entry, deleting from database: %x", iter.Key())
+		} else if of.Time.Before(oldest) {
+			folderID = string(db.keyer.FolderFromPendingFolderKey(iter.Key()))
+			l.Infof("Removing stale pending folder %s (%s) from device %s, last seen %v",
+				folderID, of.Label, device.Short(), of.Time)
+		} else {
+			// Keep entries younger or equal to the given timestamp
+			continue
+		}
+		if err := db.Delete(iter.Key()); err != nil {
+			l.Warnf("Failed to remove pending folder entry: %v", err)
+		} else if len(folderID) > 0 {
+			res = append(res, folderID)
+		}
+	}
+	return res, nil
+}
+
 // Consolidated information about a pending folder
 type PendingFolder struct {
 	OfferedBy map[protocol.DeviceID]ObservedFolder `json:"offeredBy"`

lib/events/events.go

@@ -28,7 +28,8 @@ const (
 	DeviceDiscovered
 	DeviceConnected
 	DeviceDisconnected
-	DeviceRejected
+	DeviceRejected // DEPRECATED, superseded by PendingDevicesChanged
+	PendingDevicesChanged
 	DevicePaused
 	DeviceResumed
 	LocalChangeDetected
@@ -38,7 +39,8 @@ const (
 	ItemStarted
 	ItemFinished
 	StateChanged
-	FolderRejected
+	FolderRejected // DEPRECATED, superseded by PendingFoldersChanged
+	PendingFoldersChanged
 	ConfigSaved
 	DownloadProgress
 	RemoteDownloadProgress
@@ -77,6 +79,8 @@ func (t EventType) String() string {
 		return "DeviceDisconnected"
 	case DeviceRejected:
 		return "DeviceRejected"
+	case PendingDevicesChanged:
+		return "PendingDevicesChanged"
 	case LocalChangeDetected:
 		return "LocalChangeDetected"
 	case RemoteChangeDetected:
@@ -93,6 +97,8 @@ func (t EventType) String() string {
 		return "StateChanged"
 	case FolderRejected:
 		return "FolderRejected"
+	case PendingFoldersChanged:
+		return "PendingFoldersChanged"
 	case ConfigSaved:
 		return "ConfigSaved"
 	case DownloadProgress:
@@ -158,6 +164,8 @@ func UnmarshalEventType(s string) EventType {
 		return DeviceDisconnected
 	case "DeviceRejected":
 		return DeviceRejected
+	case "PendingDevicesChanged":
+		return PendingDevicesChanged
 	case "LocalChangeDetected":
 		return LocalChangeDetected
 	case "RemoteChangeDetected":
@@ -174,6 +182,8 @@ func UnmarshalEventType(s string) EventType {
 		return StateChanged
 	case "FolderRejected":
 		return FolderRejected
+	case "PendingFoldersChanged":
+		return PendingFoldersChanged
 	case "ConfigSaved":
 		return ConfigSaved
 	case "DownloadProgress":

lib/model/model.go

@@ -1284,10 +1284,12 @@ func (m *model) ClusterConfig(deviceID protocol.DeviceID, cm protocol.ClusterCon
 }
 
 func (m *model) ccHandleFolders(folders []protocol.Folder, deviceCfg config.DeviceConfiguration, ccDeviceInfos map[string]*indexSenderStartInfo, indexSenders *indexSenderRegistry) ([]string, map[string]struct{}, error) {
+	handleTime := time.Now()
 	var folderDevice config.FolderDeviceConfiguration
 	tempIndexFolders := make([]string, 0, len(folders))
 	paused := make(map[string]struct{}, len(folders))
 	seenFolders := make(map[string]struct{}, len(folders))
+	updatedPending := make([]map[string]string, 0, len(folders))
 	deviceID := deviceCfg.DeviceID
 	for _, folder := range folders {
 		seenFolders[folder.ID] = struct{}{}
@@ -1306,6 +1308,12 @@ func (m *model) ccHandleFolders(folders []protocol.Folder, deviceCfg config.Devi
 				l.Warnf("Failed to persist pending folder entry to database: %v", err)
 			}
 			indexSenders.addPending(cfg, ccDeviceInfos[folder.ID])
+			updatedPending = append(updatedPending, map[string]string{
+				"folderID":    folder.ID,
+				"folderLabel": folder.Label,
+				"deviceID":    deviceID.String(),
+			})
+			// DEPRECATED: Only for backwards compatibility, should be removed.
 			m.evLogger.Log(events.FolderRejected, map[string]string{
 				"folder":      folder.ID,
 				"folderLabel": folder.Label,
@@ -1380,6 +1388,24 @@ func (m *model) ccHandleFolders(folders []protocol.Folder, deviceCfg config.Devi
 	}
 
 	indexSenders.removeAllExcept(seenFolders)
+	// All current pending folders were touched above, so discard any with older timestamps
+	expiredPending, err := m.db.RemovePendingFoldersBeforeTime(deviceID, handleTime)
+	if err != nil {
+		l.Infof("Could not clean up pending folder entries: %v", err)
+	}
+	if len(updatedPending) > 0 || len(expiredPending) > 0 {
+		expiredPendingList := make([]map[string]string, len(expiredPending))
+		for i, folderID := range expiredPending {
+			expiredPendingList[i] = map[string]string{
+				"folderID": folderID,
+				"deviceID": deviceID.String(),
+			}
+		}
+		m.evLogger.Log(events.PendingFoldersChanged, map[string]interface{}{
+			"added":   updatedPending,
+			"removed": expiredPendingList,
+		})
+	}
 
 	return tempIndexFolders, paused, nil
 }
@@ -2069,6 +2095,14 @@ func (m *model) OnHello(remoteID protocol.DeviceID, addr net.Addr, hello protoco
 		if err := m.db.AddOrUpdatePendingDevice(remoteID, hello.DeviceName, addr.String()); err != nil {
 			l.Warnf("Failed to persist pending device entry to database: %v", err)
 		}
+		m.evLogger.Log(events.PendingDevicesChanged, map[string][]interface{}{
+			"added": {map[string]string{
+				"deviceID": remoteID.String(),
+				"name":     hello.DeviceName,
+				"address":  addr.String(),
+			}},
+		})
+		// DEPRECATED: Only for backwards compatibility, should be removed.
 		m.evLogger.Log(events.DeviceRejected, map[string]string{
 			"name":    hello.DeviceName,
 			"device":  remoteID.String(),
@@ -2799,6 +2833,7 @@ func (m *model) CommitConfiguration(from, to config.Configuration) bool {
 }
 
 func (m *model) cleanPending(existingDevices map[protocol.DeviceID]config.DeviceConfiguration, existingFolders map[string]config.FolderConfiguration, ignoredDevices deviceIDSet, removedFolders map[string]struct{}) {
+	var removedPendingFolders []map[string]string
 	pendingFolders, err := m.db.PendingFolders()
 	if err != nil {
 		l.Infof("Could not iterate through pending folder entries for cleanup: %v", err)
@@ -2811,27 +2846,41 @@ func (m *model) cleanPending(existingDevices map[protocol.DeviceID]config.Device
 			// at all (but might become pending again).
 			l.Debugf("Discarding pending removed folder %v from all devices", folderID)
 			m.db.RemovePendingFolder(folderID)
+			removedPendingFolders = append(removedPendingFolders, map[string]string{
+				"folderID": folderID,
+			})
 			continue
 		}
 		for deviceID := range pf.OfferedBy {
 			if dev, ok := existingDevices[deviceID]; !ok {
 				l.Debugf("Discarding pending folder %v from unknown device %v", folderID, deviceID)
-				m.db.RemovePendingFolderForDevice(folderID, deviceID)
-				continue
+				goto removeFolderForDevice
 			} else if dev.IgnoredFolder(folderID) {
 				l.Debugf("Discarding now ignored pending folder %v for device %v", folderID, deviceID)
-				m.db.RemovePendingFolderForDevice(folderID, deviceID)
-				continue
+				goto removeFolderForDevice
 			}
 			if folderCfg, ok := existingFolders[folderID]; ok {
 				if folderCfg.SharedWith(deviceID) {
 					l.Debugf("Discarding now shared pending folder %v for device %v", folderID, deviceID)
-					m.db.RemovePendingFolderForDevice(folderID, deviceID)
+					goto removeFolderForDevice
 				}
 			}
+			continue
+		removeFolderForDevice:
+			m.db.RemovePendingFolderForDevice(folderID, deviceID)
+			removedPendingFolders = append(removedPendingFolders, map[string]string{
+				"folderID": folderID,
+				"deviceID": deviceID.String(),
+			})
 		}
 	}
+	if len(removedPendingFolders) > 0 {
+		m.evLogger.Log(events.PendingFoldersChanged, map[string]interface{}{
+			"removed": removedPendingFolders,
+		})
+	}
 
+	var removedPendingDevices []map[string]string
 	pendingDevices, err := m.db.PendingDevices()
 	if err != nil {
 		l.Infof("Could not iterate through pending device entries for cleanup: %v", err)
@@ -2840,14 +2889,23 @@ func (m *model) cleanPending(existingDevices map[protocol.DeviceID]config.Device
 	for deviceID := range pendingDevices {
 		if _, ok := ignoredDevices[deviceID]; ok {
 			l.Debugf("Discarding now ignored pending device %v", deviceID)
-			m.db.RemovePendingDevice(deviceID)
-			continue
+			goto removeDevice
 		}
 		if _, ok := existingDevices[deviceID]; ok {
 			l.Debugf("Discarding now added pending device %v", deviceID)
-			m.db.RemovePendingDevice(deviceID)
-			continue
+			goto removeDevice
 		}
+		continue
+	removeDevice:
+		m.db.RemovePendingDevice(deviceID)
+		removedPendingDevices = append(removedPendingDevices, map[string]string{
+			"deviceID": deviceID.String(),
+		})
+	}
+	if len(removedPendingDevices) > 0 {
+		m.evLogger.Log(events.PendingDevicesChanged, map[string]interface{}{
+			"removed": removedPendingDevices,
+		})
 	}
 }