Merge pull request #1644 from syncthing/timeout

UPnP refactor/fixes

cmd/syncthing/main.go

@@ -727,7 +727,7 @@ func setupUPnP() {
 		} else {
 			// Set up incoming port forwarding, if necessary and possible
 			port, _ := strconv.Atoi(portStr)
-			igds := upnp.Discover()
+			igds := upnp.Discover(time.Duration(cfg.Options().UPnPTimeoutS) * time.Second)
 			if len(igds) > 0 {
 				// Configure the first discovered IGD only. This is a work-around until we have a better mechanism
 				// for handling multiple IGDs, which will require changes to the global discovery service
@@ -739,7 +739,7 @@ func setupUPnP() {
 				} else {
 					l.Infof("Created UPnP port mapping for external port %d on UPnP device %s.", externalPort, igd.FriendlyIdentifier())
 
-					if opts.UPnPRenewal > 0 {
+					if opts.UPnPRenewalM > 0 {
 						go renewUPnP(port)
 					}
 				}
@@ -757,7 +757,7 @@ func setupExternalPort(igd *upnp.IGD, port int) int {
 
 	for i := 0; i < 10; i++ {
 		r := 1024 + predictableRandom.Intn(65535-1024)
-		err := igd.AddPortMapping(upnp.TCP, r, port, fmt.Sprintf("syncthing-%d", r), cfg.Options().UPnPLease*60)
+		err := igd.AddPortMapping(upnp.TCP, r, port, fmt.Sprintf("syncthing-%d", r), cfg.Options().UPnPLeaseM*60)
 		if err == nil {
 			return r
 		}
@@ -768,14 +768,16 @@ func setupExternalPort(igd *upnp.IGD, port int) int {
 func renewUPnP(port int) {
 	for {
 		opts := cfg.Options()
-		time.Sleep(time.Duration(opts.UPnPRenewal) * time.Minute)
+		time.Sleep(time.Duration(opts.UPnPRenewalM) * time.Minute)
+		// Some values might have changed while we were sleeping
+		opts = cfg.Options()
 
 		// Make sure our IGD reference isn't nil
 		if igd == nil {
 			if debugNet {
 				l.Debugln("Undefined IGD during UPnP port renewal. Re-discovering...")
 			}
-			igds := upnp.Discover()
+			igds := upnp.Discover(time.Duration(opts.UPnPTimeoutS) * time.Second)
 			if len(igds) > 0 {
 				// Configure the first discovered IGD only. This is a work-around until we have a better mechanism
 				// for handling multiple IGDs, which will require changes to the global discovery service
@@ -790,7 +792,7 @@ func renewUPnP(port int) {
 
 		// Just renew the same port that we already have
 		if externalPort != 0 {
-			err := igd.AddPortMapping(upnp.TCP, externalPort, port, "syncthing", opts.UPnPLease*60)
+			err := igd.AddPortMapping(upnp.TCP, externalPort, port, "syncthing", opts.UPnPLeaseM*60)
 			if err != nil {
 				l.Warnf("Error renewing UPnP port mapping for external port %d on device %s: %s", externalPort, igd.FriendlyIdentifier(), err.Error())
 			} else if debugNet {

internal/config/config.go

@@ -227,8 +227,9 @@ type OptionsConfiguration struct {
 	ReconnectIntervalS      int      `xml:"reconnectionIntervalS" json:"reconnectionIntervalS" default:"60"`
 	StartBrowser            bool     `xml:"startBrowser" json:"startBrowser" default:"true"`
 	UPnPEnabled             bool     `xml:"upnpEnabled" json:"upnpEnabled" default:"true"`
-	UPnPLease               int      `xml:"upnpLeaseMinutes" json:"upnpLeaseMinutes" default:"0"`
-	UPnPRenewal             int      `xml:"upnpRenewalMinutes" json:"upnpRenewalMinutes" default:"30"`
+	UPnPLeaseM              int      `xml:"upnpLeaseMinutes" json:"upnpLeaseMinutes" default:"0"`
+	UPnPRenewalM            int      `xml:"upnpRenewalMinutes" json:"upnpRenewalMinutes" default:"30"`
+	UPnPTimeoutS            int      `xml:"upnpTimeoutSeconds" json:"upnpTimeoutSeconds" default:"3"`
 	URAccepted              int      `xml:"urAccepted" json:"urAccepted"` // Accepted usage reporting version; 0 for off (undecided), -1 for off (permanently)
 	URUniqueID              string   `xml:"urUniqueID" json:"urUniqueId"` // Unique ID for reporting purposes, regenerated when UR is turned on.
 	RestartOnWakeup         bool     `xml:"restartOnWakeup" json:"restartOnWakeup" default:"true"`

internal/config/config_test.go

@@ -42,8 +42,9 @@ func TestDefaultValues(t *testing.T) {
 		ReconnectIntervalS:      60,
 		StartBrowser:            true,
 		UPnPEnabled:             true,
-		UPnPLease:               0,
-		UPnPRenewal:             30,
+		UPnPLeaseM:              0,
+		UPnPRenewalM:            30,
+		UPnPTimeoutS:            3,
 		RestartOnWakeup:         true,
 		AutoUpgradeIntervalH:    12,
 		KeepTemporariesH:        24,
@@ -147,8 +148,9 @@ func TestOverriddenValues(t *testing.T) {
 		ReconnectIntervalS:      6000,
 		StartBrowser:            false,
 		UPnPEnabled:             false,
-		UPnPLease:               60,
-		UPnPRenewal:             15,
+		UPnPLeaseM:              60,
+		UPnPRenewalM:            15,
+		UPnPTimeoutS:            15,
 		RestartOnWakeup:         false,
 		AutoUpgradeIntervalH:    24,
 		KeepTemporariesH:        48,

internal/config/testdata/overridenvalues.xml

@@ -15,6 +15,7 @@
         <upnpEnabled>false</upnpEnabled>
         <upnpLeaseMinutes>60</upnpLeaseMinutes>
         <upnpRenewalMinutes>15</upnpRenewalMinutes>
+        <upnpTimeoutSeconds>15</upnpTimeoutSeconds>
         <restartOnWakeup>false</restartOnWakeup>
         <autoUpgradeIntervalH>24</autoUpgradeIntervalH>
         <keepTemporariesH>48</keepTemporariesH>

internal/upnp/upnp.go

@@ -91,44 +91,71 @@ type upnpRoot struct {
 }
 
 // Discover discovers UPnP InternetGatewayDevices.
-// The order in which the devices appear in the result list is not deterministic.
-func Discover() []IGD {
-	var result []IGD
+// The order in which the devices appear in the results list is not deterministic.
+func Discover(timeout time.Duration) []IGD {
+	var results []IGD
 	l.Infoln("Starting UPnP discovery...")
 
-	timeout := 3
-
-	// Search for InternetGatewayDevice:2 devices
-	result = append(result, discover("urn:schemas-upnp-org:device:InternetGatewayDevice:2", timeout, result)...)
-
-	// Search for InternetGatewayDevice:1 devices
-	// InternetGatewayDevice:2 devices that correctly respond to the IGD:1 request as well will not be re-added to the result list
-	result = append(result, discover("urn:schemas-upnp-org:device:InternetGatewayDevice:1", timeout, result)...)
+	interfaces, err := net.Interfaces()
+	if err != nil {
+		l.Infoln("Listing network interfaces:", err)
+		return results
+	}
 
-	if len(result) > 0 && debug {
-		l.Debugln("UPnP discovery result:")
-		for _, resultDevice := range result {
-			l.Debugln("[" + resultDevice.uuid + "]")
+	resultChan := make(chan IGD, 16)
 
-			for _, resultService := range resultDevice.services {
-				l.Debugln("* [" + resultService.serviceID + "] " + resultService.serviceURL)
+	// Aggregator
+	go func() {
+	next:
+		for result := range resultChan {
+			for _, existingResult := range results {
+				if existingResult.uuid == result.uuid {
+					if debug {
+						l.Debugf("Skipping duplicate result %s with services:", result.uuid)
+						for _, svc := range result.services {
+							l.Debugf("* [%s] %s", svc.serviceID, svc.serviceURL)
+						}
+					}
+					goto next
+				}
+			}
+			results = append(results, result)
+			if debug {
+				l.Debugf("UPnP discovery result %s with services:", result.uuid)
+				for _, svc := range result.services {
+					l.Debugf("* [%s] %s", svc.serviceID, svc.serviceURL)
+				}
 			}
 		}
+	}()
+
+	var wg sync.WaitGroup
+	for _, intf := range interfaces {
+		for _, deviceType := range []string{"urn:schemas-upnp-org:device:InternetGatewayDevice:1", "urn:schemas-upnp-org:device:InternetGatewayDevice:2"} {
+			wg.Add(1)
+			go func(intf net.Interface, deviceType string) {
+				discover(&intf, deviceType, timeout, resultChan)
+				wg.Done()
+			}(intf, deviceType)
+		}
 	}
 
+	wg.Wait()
+	close(resultChan)
+
 	suffix := "devices"
-	if len(result) == 1 {
+	if len(results) == 1 {
 		suffix = "device"
 	}
 
-	l.Infof("UPnP discovery complete (found %d %s).", len(result), suffix)
+	l.Infof("UPnP discovery complete (found %d %s).", len(results), suffix)
 
-	return result
+	return results
 }
 
 // Search for UPnP InternetGatewayDevices for <timeout> seconds, ignoring responses from any devices listed in knownDevices.
 // The order in which the devices appear in the result list is not deterministic
-func discover(deviceType string, timeout int, knownDevices []IGD) []IGD {
+func discover(intf *net.Interface, deviceType string, timeout time.Duration, results chan<- IGD) {
 	ssdp := &net.UDPAddr{IP: []byte{239, 255, 255, 250}, Port: 1900}
 
 	tpl := `M-SEARCH * HTTP/1.1
@@ -138,44 +165,39 @@ Man: "ssdp:discover"
 Mx: %d
 
 `
-	searchStr := fmt.Sprintf(tpl, deviceType, timeout)
+	searchStr := fmt.Sprintf(tpl, deviceType, timeout/time.Second)
 
 	search := []byte(strings.Replace(searchStr, "\n", "\r\n", -1))
 
 	if debug {
-		l.Debugln("Starting discovery of device type " + deviceType + "...")
+		l.Debugln("Starting discovery of device type " + deviceType + " on " + intf.Name)
 	}
 
-	var results []IGD
-	resultChannel := make(chan IGD, 8)
-
-	socket, err := net.ListenMulticastUDP("udp4", nil, &net.UDPAddr{IP: ssdp.IP})
+	socket, err := net.ListenMulticastUDP("udp4", intf, &net.UDPAddr{IP: ssdp.IP})
 	if err != nil {
 		l.Infoln(err)
-		return results
+		return
 	}
 	defer socket.Close() // Make sure our socket gets closed
 
-	err = socket.SetDeadline(time.Now().Add(time.Duration(timeout) * time.Second))
+	err = socket.SetDeadline(time.Now().Add(timeout))
 	if err != nil {
 		l.Infoln(err)
-		return results
+		return
 	}
 
 	if debug {
-		l.Debugln("Sending search request for device type " + deviceType + "...")
+		l.Debugln("Sending search request for device type " + deviceType + " on " + intf.Name)
 	}
 
-	var resultWaitGroup sync.WaitGroup
-
 	_, err = socket.WriteTo(search, ssdp)
 	if err != nil {
 		l.Infoln(err)
-		return results
+		return
 	}
 
 	if debug {
-		l.Debugln("Listening for UPnP response for device type " + deviceType + "...")
+		l.Debugln("Listening for UPnP response for device type " + deviceType + " on " + intf.Name)
 	}
 
 	// Listen for responses until a timeout is reached
@@ -186,67 +208,40 @@ Mx: %d
 			if e, ok := err.(net.Error); !ok || !e.Timeout() {
 				l.Infoln(err) //legitimate error, not a timeout.
 			}
-
 			break
-		} else {
-			// Process results in a separate go routine so we can immediately return to listening for more responses
-			resultWaitGroup.Add(1)
-			go handleSearchResponse(deviceType, knownDevices, resp, n, resultChannel, &resultWaitGroup)
 		}
-	}
-
-	// Wait for all result handlers to finish processing, then close result channel
-	resultWaitGroup.Wait()
-	close(resultChannel)
-
-	// Collect our results from the result handlers using the result channel
-	for result := range resultChannel {
-		// Check for existing results (some routers send multiple response packets)
-		for _, existingResult := range results {
-			if existingResult.uuid == result.uuid {
-				if debug {
-					l.Debugln("Already processed device with UUID", existingResult.uuid, "continuing...")
-				}
-				continue
-			}
+		igd, err := parseResponse(deviceType, resp[:n])
+		if err != nil {
+			l.Infoln(err)
+			continue
 		}
-
-		// No existing results, okay to append
-		results = append(results, result)
+		results <- igd
 	}
-
 	if debug {
-		l.Debugln("Discovery for device type " + deviceType + " finished.")
+		l.Debugln("Discovery for device type " + deviceType + " on " + intf.Name + " finished.")
 	}
-
-	return results
 }
 
-func handleSearchResponse(deviceType string, knownDevices []IGD, resp []byte, length int, resultChannel chan<- IGD, resultWaitGroup *sync.WaitGroup) {
-	defer resultWaitGroup.Done() // Signal when we've finished processing
-
+func parseResponse(deviceType string, resp []byte) (IGD, error) {
 	if debug {
-		l.Debugln("Handling UPnP response:\n\n" + string(resp[:length]))
+		l.Debugln("Handling UPnP response:\n\n" + string(resp))
 	}
 
-	reader := bufio.NewReader(bytes.NewBuffer(resp[:length]))
+	reader := bufio.NewReader(bytes.NewBuffer(resp))
 	request := &http.Request{}
 	response, err := http.ReadResponse(reader, request)
 	if err != nil {
-		l.Infoln(err)
-		return
+		return IGD{}, err
 	}
 
 	respondingDeviceType := response.Header.Get("St")
 	if respondingDeviceType != deviceType {
-		l.Infoln("Unrecognized UPnP device of type " + respondingDeviceType)
-		return
+		return IGD{}, errors.New("unrecognized UPnP device of type " + respondingDeviceType)
 	}
 
 	deviceDescriptionLocation := response.Header.Get("Location")
 	if deviceDescriptionLocation == "" {
-		l.Infoln("Invalid IGD response: no location specified.")
-		return
+		return IGD{}, errors.New("invalid IGD response: no location specified.")
 	}
 
 	deviceDescriptionURL, err := url.Parse(deviceDescriptionLocation)
@@ -257,8 +252,7 @@ func handleSearchResponse(deviceType string, knownDevices []IGD, resp []byte, le
 
 	deviceUSN := response.Header.Get("USN")
 	if deviceUSN == "" {
-		l.Infoln("Invalid IGD response: USN not specified.")
-		return
+		return IGD{}, errors.New("invalid IGD response: USN not specified.")
 	}
 
 	deviceUUID := strings.TrimLeft(strings.Split(deviceUSN, "::")[0], "uuid:")
@@ -267,39 +261,25 @@ func handleSearchResponse(deviceType string, knownDevices []IGD, resp []byte, le
 		l.Infoln("Invalid IGD response: invalid device UUID", deviceUUID, "(continuing anyway)")
 	}
 
-	// Don't re-add devices that are already known
-	for _, knownDevice := range knownDevices {
-		if deviceUUID == knownDevice.uuid {
-			if debug {
-				l.Debugln("Ignoring known device with UUID " + deviceUUID)
-			}
-			return
-		}
-	}
-
 	response, err = http.Get(deviceDescriptionLocation)
 	if err != nil {
-		l.Infoln(err)
-		return
+		return IGD{}, err
 	}
 	defer response.Body.Close()
 
 	if response.StatusCode >= 400 {
-		l.Infoln(errors.New(response.Status))
-		return
+		return IGD{}, errors.New("bad status code:" + response.Status)
 	}
 
 	var upnpRoot upnpRoot
 	err = xml.NewDecoder(response.Body).Decode(&upnpRoot)
 	if err != nil {
-		l.Infoln(err)
-		return
+		return IGD{}, err
 	}
 
 	services, err := getServiceDescriptions(deviceDescriptionLocation, upnpRoot.Device)
 	if err != nil {
-		l.Infoln(err)
-		return
+		return IGD{}, err
 	}
 
 	// Figure out our IP number, on the network used to reach the IGD.
@@ -308,23 +288,16 @@ func handleSearchResponse(deviceType string, knownDevices []IGD, resp []byte, le
 	// suggestions on a better way to do this...
 	localIPAddress, err := localIP(deviceDescriptionURL)
 	if err != nil {
-		l.Infoln(err)
-		return
+		return IGD{}, err
 	}
 
-	igd := IGD{
+	return IGD{
 		uuid:           deviceUUID,
 		friendlyName:   upnpRoot.Device.FriendlyName,
 		url:            deviceDescriptionURL,
 		services:       services,
 		localIPAddress: localIPAddress,
-	}
-
-	resultChannel <- igd
-
-	if debug {
-		l.Debugln("Finished handling of UPnP response.")
-	}
+	}, nil
 }
 
 func localIP(url *url.URL) (string, error) {