Failed to set UPnP port mapping

UPnP is enabled in the Netgear Router

Regards Ric

Please provide logs as explained in:

[LP75R] 2015/05/17 16:41:39.287683 main.go:466: INFO: syncthing v0.11.5 (go1.4.2 windows-386 default) unknown-user@syncthing-builder 2015-05-15 08:46:47 UTC [LP75R] 2015/05/17 16:41:39.296683 main.go:467: INFO: My ID: LP75RYS-OYBFMRF-XZR4Y3W-NXZW4Y4-UGVX64H-IUIFRXL-OEHVP33-55K4IQP [LP75R] 2015/05/17 16:41:39.303684 main.go:740: INFO: Database block cache capacity 26523 KiB [LP75R] 2015/05/17 16:41:39.377688 main.go:795: INFO: Starting web GUI on http://127.0.0.1:8384/ [LP75R] 2015/05/17 16:41:44.066956 main.go:870: INFO: Starting local discovery announcements [LP75R] 2015/05/17 16:41:44.135960 discover.go:131: INFO: Local discovery over IPv6 unavailable [LP75R] 2015/05/17 16:41:44.135960 main.go:875: INFO: Starting global discovery announcements [LP75R] 2015/05/17 16:41:44.140960 main.go:646: OK: Ready to synchronize KamR (read-write) [LP75R] 2015/05/17 16:41:44.140960 main.go:662: INFO: Device BHGBHX2-5BWXI2P-FEH5NTT-5W5JXBF-JQFGQ7H-7LOPDDR-R65LEVD-HY5BCQX is “Leni” at [dynamic] [LP75R] 2015/05/17 16:41:44.141960 main.go:662: INFO: Device LP75RYS-OYBFMRF-XZR4Y3W-NXZW4Y4-UGVX64H-IUIFRXL-OEHVP33-55K4IQP is “SERVER” at [dynamic] [LP75R] 2015/05/17 16:41:44.141960 main.go:662: INFO: Device NICMCM3-NSXK7FL-32TFLJO-AIXOELQ-A2OGDF5-KNVKJXI-ZJCNW3U-45RGSQE is “Handy Ric” at [dynamic] [LP75R] 2015/05/17 16:41:44.168962 upnp.go:171: DEBUG: Starting discovery of device type urn:schemas-upnp-org:device:InternetGatewayDevice:1 on {863DEC64-816B-4CFD-B681-85D988B65C6C} [LP75R] 2015/05/17 16:41:44.174962 upnp.go:171: DEBUG: Starting discovery of device type urn:schemas-upnp-org:device:InternetGatewayDevice:1 on {DF62A937-4C97-4120-A3C1-A3B7D0F3F829} [LP75R] 2015/05/17 16:41:44.178962 upnp.go:171: DEBUG: Starting discovery of device type urn:schemas-upnp-org:device:InternetGatewayDevice:2 on {DF62A937-4C97-4120-A3C1-A3B7D0F3F829} [LP75R] 2015/05/17 16:41:44.182963 upnp.go:171: DEBUG: Starting discovery of device type urn:schemas-upnp-org:device:InternetGatewayDevice:2 on {863DEC64-816B-4CFD-B681-85D988B65C6C} [LP75R] 2015/05/17 16:41:44.216965 rwfolder.go:275: INFO: Completed initial scan (rw) of folder KamR [LP75R] 2015/05/17 16:41:44.248966 upnp.go:190: DEBUG: Sending search request for device type urn:schemas-upnp-org:device:InternetGatewayDevice:1 on {DF62A937-4C97-4120-A3C1-A3B7D0F3F829} [LP75R] 2015/05/17 16:41:44.249967 upnp.go:190: DEBUG: Sending search request for device type urn:schemas-upnp-org:device:InternetGatewayDevice:1 on {863DEC64-816B-4CFD-B681-85D988B65C6C} [LP75R] 2015/05/17 16:41:44.249967 upnp.go:200: DEBUG: Listening for UPnP response for device type urn:schemas-upnp-org:device:InternetGatewayDevice:1 on {863DEC64-816B-4CFD-B681-85D988B65C6C} [LP75R] 2015/05/17 16:41:44.255967 upnp.go:200: DEBUG: Listening for UPnP response for device type urn:schemas-upnp-org:device:InternetGatewayDevice:1 on {DF62A937-4C97-4120-A3C1-A3B7D0F3F829} [LP75R] 2015/05/17 16:41:44.292969 upnp.go:190: DEBUG: Sending search request for device type urn:schemas-upnp-org:device:InternetGatewayDevice:2 on {DF62A937-4C97-4120-A3C1-A3B7D0F3F829} [LP75R] 2015/05/17 16:41:44.293969 upnp.go:200: DEBUG: Listening for UPnP response for device type urn:schemas-upnp-org:device:InternetGatewayDevice:2 on {DF62A937-4C97-4120-A3C1-A3B7D0F3F829} [LP75R] 2015/05/17 16:41:44.295969 upnp.go:190: DEBUG: Sending search request for device type urn:schemas-upnp-org:device:InternetGatewayDevice:2 on {863DEC64-816B-4CFD-B681-85D988B65C6C} [LP75R] 2015/05/17 16:41:44.295969 upnp.go:200: DEBUG: Listening for UPnP response for device type urn:schemas-upnp-org:device:InternetGatewayDevice:2 on {863DEC64-816B-4CFD-B681-85D988B65C6C} [LP75R] 2015/05/17 16:41:54.252539 upnp.go:221: DEBUG: Discovery for device type urn:schemas-upnp-org:device:InternetGatewayDevice:1 on {863DEC64-816B-4CFD-B681-85D988B65C6C} finished. [LP75R] 2015/05/17 16:41:54.253539 upnp.go:221: DEBUG: Discovery for device type urn:schemas-upnp-org:device:InternetGatewayDevice:1 on {DF62A937-4C97-4120-A3C1-A3B7D0F3F829} finished. [LP75R] 2015/05/17 16:41:54.293541 upnp.go:221: DEBUG: Discovery for device type urn:schemas-upnp-org:device:InternetGatewayDevice:2 on {DF62A937-4C97-4120-A3C1-A3B7D0F3F829} finished. [LP75R] 2015/05/17 16:41:54.296541 upnp.go:221: DEBUG: Discovery for device type urn:schemas-upnp-org:device:InternetGatewayDevice:2 on {863DEC64-816B-4CFD-B681-85D988B65C6C} finished. [LP75R] 2015/05/17 16:41:54.296541 upnpsvc.go:46: INFO: No UPnP device detected [LP75R] 2015/05/17 16:41:55.717622 usage_report.go:144: INFO: Starting usage reporting

Well this time it’s not even finding the router, so the log does not contain anything useful.

OK i resetet the router an now this is it.

[BHGBH] 2015/05/18 09:23:34.194211 main.go:466: INFO: syncthing v0.11.5 (go1.4.2 windows-amd64 default) unknown-user@syncthing-builder 2015-05-15 08:46:47 UTC [BHGBH] 2015/05/18 09:23:34.197212 main.go:467: INFO: My ID: BHGBHX2-5BWXI2P-FEH5NTT-5W5JXBF-JQFGQ7H-7LOPDDR-R65LEVD-HY5BCQX [BHGBH] 2015/05/18 09:23:34.200212 main.go:740: INFO: Database block cache capacity 63300 KiB [BHGBH] 2015/05/18 09:23:35.089263 main.go:795: INFO: Starting web GUI on http://127.0.0.1:8384/ [BHGBH] 2015/05/18 09:23:37.309390 main.go:870: INFO: Starting local discovery announcements [BHGBH] 2015/05/18 09:23:37.317390 discover.go:131: INFO: Local discovery over IPv6 unavailable [BHGBH] 2015/05/18 09:23:37.317390 main.go:875: INFO: Starting global discovery announcements [BHGBH] 2015/05/18 09:23:37.319390 main.go:646: OK: Ready to synchronize Dokumente (read-write) [BHGBH] 2015/05/18 09:23:37.320390 main.go:646: OK: Ready to synchronize KamS (read-write) [BHGBH] 2015/05/18 09:23:37.320390 main.go:646: OK: Ready to synchronize WaRB (read-write) [BHGBH] 2015/05/18 09:23:37.320390 main.go:646: OK: Ready to synchronize WaRV (read-write) [BHGBH] 2015/05/18 09:23:37.320390 main.go:646: OK: Ready to synchronize 2015 (read-write) [BHGBH] 2015/05/18 09:23:37.320390 main.go:646: OK: Ready to synchronize Bilder (read-write) [BHGBH] 2015/05/18 09:23:37.320390 main.go:646: OK: Ready to synchronize Richard (read-write) [BHGBH] 2015/05/18 09:23:37.320390 main.go:646: OK: Ready to synchronize Videos_Privat (read-write) [BHGBH] 2015/05/18 09:23:37.320390 main.go:646: OK: Ready to synchronize WaSB (read-write) [BHGBH] 2015/05/18 09:23:37.320390 main.go:646: OK: Ready to synchronize WaSV (read-write) [BHGBH] 2015/05/18 09:23:37.320390 main.go:646: OK: Ready to synchronize Wichtig (read-write) [BHGBH] 2015/05/18 09:23:37.320390 main.go:646: OK: Ready to synchronize KamR (read-write) [BHGBH] 2015/05/18 09:23:37.320390 main.go:646: OK: Ready to synchronize Musik (read-write) [BHGBH] 2015/05/18 09:23:37.321390 main.go:662: INFO: Device BHGBHX2-5BWXI2P-FEH5NTT-5W5JXBF-JQFGQ7H-7LOPDDR-R65LEVD-HY5BCQX is “Leni” at [dynamic] [BHGBH] 2015/05/18 09:23:37.321390 main.go:662: INFO: Device LP75RYS-OYBFMRF-XZR4Y3W-NXZW4Y4-UGVX64H-IUIFRXL-OEHVP33-55K4IQP is “Server” at [dynamic] [BHGBH] 2015/05/18 09:23:37.321390 main.go:662: INFO: Device NICMCM3-NSXK7FL-32TFLJO-AIXOELQ-A2OGDF5-KNVKJXI-ZJCNW3U-45RGSQE is “Handy Ric” at [dynamic] [BHGBH] 2015/05/18 09:23:37.321390 main.go:662: INFO: Device RRW7XTO-4FHQU4K-JDYJRSU-IZT3GK4-PMRAGOA-V3DF6GS-NBPS6OA-ZWZZPQA is “Handy Syli” at [dynamic] [BHGBH] 2015/05/18 09:23:37.322390 usage_report.go:144: INFO: Starting usage reporting [BHGBH] 2015/05/18 09:23:37.330391 upnp.go:171: DEBUG: Starting discovery of device type urn:schemas-upnp-org:device:InternetGatewayDevice:1 on {B096932C-A245-4F1E-B974-2C6583964162} [BHGBH] 2015/05/18 09:23:37.334391 upnp.go:171: DEBUG: Starting discovery of device type urn:schemas-upnp-org:device:InternetGatewayDevice:2 on {B096932C-A245-4F1E-B974-2C6583964162} [BHGBH] 2015/05/18 09:23:37.341391 upnp.go:190: DEBUG: Sending search request for device type urn:schemas-upnp-org:device:InternetGatewayDevice:1 on {B096932C-A245-4F1E-B974-2C6583964162} [BHGBH] 2015/05/18 09:23:37.352392 upnp.go:190: DEBUG: Sending search request for device type urn:schemas-upnp-org:device:InternetGatewayDevice:2 on {B096932C-A245-4F1E-B974-2C6583964162} [BHGBH] 2015/05/18 09:23:37.358392 rwfolder.go:275: INFO: Completed initial scan (rw) of folder Wichtig [BHGBH] 2015/05/18 09:23:37.358392 upnp.go:200: DEBUG: Listening for UPnP response for device type urn:schemas-upnp-org:device:InternetGatewayDevice:1 on {B096932C-A245-4F1E-B974-2C6583964162} [BHGBH] 2015/05/18 09:23:37.364393 rwfolder.go:275: INFO: Completed initial scan (rw) of folder WaRB [BHGBH] 2015/05/18 09:23:37.368393 rwfolder.go:275: INFO: Completed initial scan (rw) of folder Musik [BHGBH] 2015/05/18 09:23:37.370393 rwfolder.go:275: INFO: Completed initial scan (rw) of folder KamR [BHGBH] 2015/05/18 09:23:37.373393 rwfolder.go:275: INFO: Completed initial scan (rw) of folder KamS [BHGBH] 2015/05/18 09:23:37.373393 upnp.go:227: DEBUG: Handling UPnP response:

HTTP/1.1 200 OK

ST: urn:schemas-upnp-org:device:InternetGatewayDevice:1

LOCATION: http://192.168.1.1:5000/Public_UPNP_gatedesc.xml

SERVER: Linux/2.6.12, UPnP/1.0, NETGEAR-UPNP/1.0

EXT:

CACHE-CONTROL: max-age=3600

USN: uuid:656f09aa-320e-8a03-365e-af5f6f66a317::urn:schemas-upnp-org:device:InternetGatewayDevice:1

[BHGBH] 2015/05/18 09:23:37.373393 upnp.go:200: DEBUG: Listening for UPnP response for device type urn:schemas-upnp-org:device:InternetGatewayDevice:2 on {B096932C-A245-4F1E-B974-2C6583964162} [BHGBH] 2015/05/18 09:23:37.376393 rwfolder.go:275: INFO: Completed initial scan (rw) of folder Richard [BHGBH] 2015/05/18 09:23:37.521402 rwfolder.go:275: INFO: Completed initial scan (rw) of folder WaRV [BHGBH] 2015/05/18 09:23:37.597406 rwfolder.go:275: INFO: Completed initial scan (rw) of folder WaSB [BHGBH] 2015/05/18 09:23:37.654409 rwfolder.go:275: INFO: Completed initial scan (rw) of folder WaSV [BHGBH] 2015/05/18 09:23:37.689411 upnp.go:398: DEBUG: [http://192.168.1.1:5000/Public_UPNP_gatedesc.xml] Found urn:schemas-upnp-org:service:WANIPConnection:1 with URL http://192.168.1.1:5000/Public_UPNP_C3 [BHGBH] 2015/05/18 09:23:37.689411 upnp.go:398: DEBUG: [http://192.168.1.1:5000/Public_UPNP_gatedesc.xml] Found urn:schemas-upnp-org:service:WANPPPConnection:1 with URL http://192.168.1.1:5000/Public_UPNP_C5 [BHGBH] 2015/05/18 09:23:37.700412 upnp.go:122: DEBUG: UPnP discovery result 656f09aa-320e-8a03-365e-af5f6f66a317 with services: [BHGBH] 2015/05/18 09:23:37.700412 upnp.go:124: DEBUG: * [urn:upnp-org:serviceId:WANIPConn1] http://192.168.1.1:5000/Public_UPNP_C3 [BHGBH] 2015/05/18 09:23:37.700412 upnp.go:124: DEBUG: * [urn:upnp-org:serviceId:WANPPPConn1] http://192.168.1.1:5000/Public_UPNP_C5 [BHGBH] 2015/05/18 09:23:37.750415 rwfolder.go:275: INFO: Completed initial scan (rw) of folder 2015 [BHGBH] 2015/05/18 09:23:37.826419 rwfolder.go:275: INFO: Completed initial scan (rw) of folder Videos_Privat [BHGBH] 2015/05/18 09:23:38.494457 rwfolder.go:275: INFO: Completed initial scan (rw) of folder Dokumente [BHGBH] 2015/05/18 09:23:41.227614 rwfolder.go:275: INFO: Completed initial scan (rw) of folder Bilder [BHGBH] 2015/05/18 09:23:47.341963 upnp.go:221: DEBUG: Discovery for device type urn:schemas-upnp-org:device:InternetGatewayDevice:1 on {B096932C-A245-4F1E-B974-2C6583964162} finished. [BHGBH] 2015/05/18 09:23:47.352964 upnp.go:221: DEBUG: Discovery for device type urn:schemas-upnp-org:device:InternetGatewayDevice:2 on {B096932C-A245-4F1E-B974-2C6583964162} finished. [BHGBH] 2015/05/18 09:23:47.352964 upnp.go:460: DEBUG: SOAP Request URL: http://192.168.1.1:5000/Public_UPNP_C3 [BHGBH] 2015/05/18 09:23:47.352964 upnp.go:461: DEBUG: SOAP Action: [BHGBH] 2015/05/18 09:23:47.352964 upnp.go:462: DEBUG: SOAP Request:

<?xml version="1.0" ?>
<s:Envelope xmlns:s="http://schemas.xmlsoap.org/soap/envelope/" s:encodingStyle="http://schemas.xmlsoap.org/soap/encoding/">
<s:Body><u:AddPortMapping xmlns:u="urn:schemas-upnp-org:service:WANIPConnection:1">
<NewRemoteHost></NewRemoteHost>
<NewExternalPort>32945</NewExternalPort>
<NewProtocol>TCP</NewProtocol>
<NewInternalPort>22000</NewInternalPort>
<NewInternalClient>192.168.1.6</NewInternalClient>
<NewEnabled>1</NewEnabled>
<NewPortMappingDescription>syncthing-32945</NewPortMappingDescription>
<NewLeaseDuration>3600</NewLeaseDuration>
</u:AddPortMapping></s:Body>
</s:Envelope>

[BHGBH] 2015/05/18 09:23:47.358964 upnp.go:475: DEBUG: SOAP Response:

<s:Envelope xmlns:s=“http://schemas.xmlsoap.org/soap/envelope/” s:encodingStyle=“http://schemas.xmlsoap.org/soap/encoding/”>

<s:Body>

<s:Fault>

s:Client

UPnPError

725

OnlyPermanentLeasesSupported

</s:Fault>

</s:Body>

</s:Envelope>

[BHGBH] 2015/05/18 09:23:47.358964 upnp.go:460: DEBUG: SOAP Request URL: http://192.168.1.1:5000/Public_UPNP_C3 [BHGBH] 2015/05/18 09:23:47.358964 upnp.go:461: DEBUG: SOAP Action: [BHGBH] 2015/05/18 09:23:47.358964 upnp.go:462: DEBUG: SOAP Request:

<?xml version="1.0" ?>
<s:Envelope xmlns:s="http://schemas.xmlsoap.org/soap/envelope/" s:encodingStyle="http://schemas.xmlsoap.org/soap/encoding/">
<s:Body><u:AddPortMapping xmlns:u="urn:schemas-upnp-org:service:WANIPConnection:1">
<NewRemoteHost></NewRemoteHost>
<NewExternalPort>8712</NewExternalPort>
<NewProtocol>TCP</NewProtocol>
<NewInternalPort>22000</NewInternalPort>
<NewInternalClient>192.168.1.6</NewInternalClient>
<NewEnabled>1</NewEnabled>
<NewPortMappingDescription>syncthing-8712</NewPortMappingDescription>
<NewLeaseDuration>3600</NewLeaseDuration>
</u:AddPortMapping></s:Body>
</s:Envelope>

[BHGBH] 2015/05/18 09:23:47.363965 upnp.go:475: DEBUG: SOAP Response:

<s:Envelope xmlns:s=“http://schemas.xmlsoap.org/soap/envelope/” s:encodingStyle=“http://schemas.xmlsoap.org/soap/encoding/”>

<s:Body>

<s:Fault>

s:Client

UPnPError

725

OnlyPermanentLeasesSupported

</s:Fault>

</s:Body>

</s:Envelope>

[BHGBH] 2015/05/18 09:23:47.363965 upnp.go:460: DEBUG: SOAP Request URL: http://192.168.1.1:5000/Public_UPNP_C3 [BHGBH] 2015/05/18 09:23:47.363965 upnp.go:461: DEBUG: SOAP Action: [BHGBH] 2015/05/18 09:23:47.363965 upnp.go:462: DEBUG: SOAP Request:

<?xml version="1.0" ?>
<s:Envelope xmlns:s="http://schemas.xmlsoap.org/soap/envelope/" s:encodingStyle="http://schemas.xmlsoap.org/soap/encoding/">
<s:Body><u:AddPortMapping xmlns:u="urn:schemas-upnp-org:service:WANIPConnection:1">
<NewRemoteHost></NewRemoteHost>
<NewExternalPort>64156</NewExternalPort>
<NewProtocol>TCP</NewProtocol>
<NewInternalPort>22000</NewInternalPort>
<NewInternalClient>192.168.1.6</NewInternalClient>
<NewEnabled>1</NewEnabled>
<NewPortMappingDescription>syncthing-64156</NewPortMappingDescription>
<NewLeaseDuration>3600</NewLeaseDuration>
</u:AddPortMapping></s:Body>
</s:Envelope>

[BHGBH] 2015/05/18 09:23:47.373965 upnp.go:475: DEBUG: SOAP Response:

<s:Envelope xmlns:s=“http://schemas.xmlsoap.org/soap/envelope/” s:encodingStyle=“http://schemas.xmlsoap.org/soap/encoding/”>

<s:Body>

<s:Fault>

s:Client

UPnPError

725

OnlyPermanentLeasesSupported

</s:Fault>

</s:Body>

</s:Envelope>

[BHGBH] 2015/05/18 09:23:47.373965 upnp.go:460: DEBUG: SOAP Request URL: http://192.168.1.1:5000/Public_UPNP_C3 [BHGBH] 2015/05/18 09:23:47.373965 upnp.go:461: DEBUG: SOAP Action: [BHGBH] 2015/05/18 09:23:47.373965 upnp.go:462: DEBUG: SOAP Request:

<?xml version="1.0" ?>
<s:Envelope xmlns:s="http://schemas.xmlsoap.org/soap/envelope/" s:encodingStyle="http://schemas.xmlsoap.org/soap/encoding/">
<s:Body><u:AddPortMapping xmlns:u="urn:schemas-upnp-org:service:WANIPConnection:1">
<NewRemoteHost></NewRemoteHost>
<NewExternalPort>8564</NewExternalPort>
<NewProtocol>TCP</NewProtocol>
<NewInternalPort>22000</NewInternalPort>
<NewInternalClient>192.168.1.6</NewInternalClient>
<NewEnabled>1</NewEnabled>
<NewPortMappingDescription>syncthing-8564</NewPortMappingDescription>
<NewLeaseDuration>3600</NewLeaseDuration>
</u:AddPortMapping></s:Body>
</s:Envelope>

[BHGBH] 2015/05/18 09:23:47.386966 upnp.go:475: DEBUG: SOAP Response:

<s:Envelope xmlns:s=“http://schemas.xmlsoap.org/soap/envelope/” s:encodingStyle=“http://schemas.xmlsoap.org/soap/encoding/”>

<s:Body>

<s:Fault>

s:Client

UPnPError

725

OnlyPermanentLeasesSupported

</s:Fault>

</s:Body>

</s:Envelope>

[BHGBH] 2015/05/18 09:23:47.386966 upnp.go:460: DEBUG: SOAP Request URL: http://192.168.1.1:5000/Public_UPNP_C3 [BHGBH] 2015/05/18 09:23:47.386966 upnp.go:461: DEBUG: SOAP Action: [BHGBH] 2015/05/18 09:23:47.386966 upnp.go:462: DEBUG: SOAP Request:

<?xml version="1.0" ?>
<s:Envelope xmlns:s="http://schemas.xmlsoap.org/soap/envelope/" s:encodingStyle="http://schemas.xmlsoap.org/soap/encoding/">
<s:Body><u:AddPortMapping xmlns:u="urn:schemas-upnp-org:service:WANIPConnection:1">
<NewRemoteHost></NewRemoteHost>
<NewExternalPort>38606</NewExternalPort>
<NewProtocol>TCP</NewProtocol>
<NewInternalPort>22000</NewInternalPort>
<NewInternalClient>192.168.1.6</NewInternalClient>
<NewEnabled>1</NewEnabled>
<NewPortMappingDescription>syncthing-38606</NewPortMappingDescription>
<NewLeaseDuration>3600</NewLeaseDuration>
</u:AddPortMapping></s:Body>
</s:Envelope>

[BHGBH] 2015/05/18 09:23:47.391966 upnp.go:475: DEBUG: SOAP Response:

<s:Envelope xmlns:s=“http://schemas.xmlsoap.org/soap/envelope/” s:encodingStyle=“http://schemas.xmlsoap.org/soap/encoding/”>

<s:Body>

<s:Fault>

s:Client

UPnPError

725

OnlyPermanentLeasesSupported

</s:Fault>

</s:Body>

</s:Envelope>

[BHGBH] 2015/05/18 09:23:47.391966 upnp.go:460: DEBUG: SOAP Request URL: http://192.168.1.1:5000/Public_UPNP_C3 [BHGBH] 2015/05/18 09:23:47.391966 upnp.go:461: DEBUG: SOAP Action: [BHGBH] 2015/05/18 09:23:47.391966 upnp.go:462: DEBUG: SOAP Request:

<?xml version="1.0" ?>
<s:Envelope xmlns:s="http://schemas.xmlsoap.org/soap/envelope/" s:encodingStyle="http://schemas.xmlsoap.org/soap/encoding/">
<s:Body><u:AddPortMapping xmlns:u="urn:schemas-upnp-org:service:WANIPConnection:1">
<NewRemoteHost></NewRemoteHost>
<NewExternalPort>32585</NewExternalPort>
<NewProtocol>TCP</NewProtocol>
<NewInternalPort>22000</NewInternalPort>
<NewInternalClient>192.168.1.6</NewInternalClient>
<NewEnabled>1</NewEnabled>
<NewPortMappingDescription>syncthing-32585</NewPortMappingDescription>
<NewLeaseDuration>3600</NewLeaseDuration>
</u:AddPortMapping></s:Body>
</s:Envelope>

[BHGBH] 2015/05/18 09:23:47.395967 upnp.go:475: DEBUG: SOAP Response:

<s:Envelope xmlns:s=“http://schemas.xmlsoap.org/soap/envelope/” s:encodingStyle=“http://schemas.xmlsoap.org/soap/encoding/”>

<s:Body>

<s:Fault>

s:Client

UPnPError

725

OnlyPermanentLeasesSupported

</s:Fault>

</s:Body>

</s:Envelope>

[BHGBH] 2015/05/18 09:23:47.395967 upnp.go:460: DEBUG: SOAP Request URL: http://192.168.1.1:5000/Public_UPNP_C3 [BHGBH] 2015/05/18 09:23:47.395967 upnp.go:461: DEBUG: SOAP Action: [BHGBH] 2015/05/18 09:23:47.395967 upnp.go:462: DEBUG: SOAP Request:

<?xml version="1.0" ?>
<s:Envelope xmlns:s="http://schemas.xmlsoap.org/soap/envelope/" s:encodingStyle="http://schemas.xmlsoap.org/soap/encoding/">
<s:Body><u:AddPortMapping xmlns:u="urn:schemas-upnp-org:service:WANIPConnection:1">
<NewRemoteHost></NewRemoteHost>
<NewExternalPort>50071</NewExternalPort>
<NewProtocol>TCP</NewProtocol>
<NewInternalPort>22000</NewInternalPort>
<NewInternalClient>192.168.1.6</NewInternalClient>
<NewEnabled>1</NewEnabled>
<NewPortMappingDescription>syncthing-50071</NewPortMappingDescription>
<NewLeaseDuration>3600</NewLeaseDuration>
</u:AddPortMapping></s:Body>
</s:Envelope>

[BHGBH] 2015/05/18 09:23:47.473971 upnp.go:475: DEBUG: SOAP Response:

<s:Envelope xmlns:s=“http://schemas.xmlsoap.org/soap/envelope/” s:encodingStyle=“http://schemas.xmlsoap.org/soap/encoding/”>

<s:Body>

<s:Fault>

s:Client

UPnPError

725

OnlyPermanentLeasesSupported

</s:Fault>

</s:Body>

</s:Envelope>

[BHGBH] 2015/05/18 09:23:47.473971 upnp.go:460: DEBUG: SOAP Request URL: http://192.168.1.1:5000/Public_UPNP_C3 [BHGBH] 2015/05/18 09:23:47.473971 upnp.go:461: DEBUG: SOAP Action: [BHGBH] 2015/05/18 09:23:47.473971 upnp.go:462: DEBUG: SOAP Request:

<?xml version="1.0" ?>
<s:Envelope xmlns:s="http://schemas.xmlsoap.org/soap/envelope/" s:encodingStyle="http://schemas.xmlsoap.org/soap/encoding/">
<s:Body><u:AddPortMapping xmlns:u="urn:schemas-upnp-org:service:WANIPConnection:1">
<NewRemoteHost></NewRemoteHost>
<NewExternalPort>5649</NewExternalPort>
<NewProtocol>TCP</NewProtocol>
<NewInternalPort>22000</NewInternalPort>
<NewInternalClient>192.168.1.6</NewInternalClient>
<NewEnabled>1</NewEnabled>
<NewPortMappingDescription>syncthing-5649</NewPortMappingDescription>
<NewLeaseDuration>3600</NewLeaseDuration>
</u:AddPortMapping></s:Body>
</s:Envelope>

[BHGBH] 2015/05/18 09:23:47.477971 upnp.go:475: DEBUG: SOAP Response:

<s:Envelope xmlns:s=“http://schemas.xmlsoap.org/soap/envelope/” s:encodingStyle=“http://schemas.xmlsoap.org/soap/encoding/”>

<s:Body>

<s:Fault>

s:Client

UPnPError

725

OnlyPermanentLeasesSupported

</s:Fault>

</s:Body>

</s:Envelope>

[BHGBH] 2015/05/18 09:23:47.477971 upnp.go:460: DEBUG: SOAP Request URL: http://192.168.1.1:5000/Public_UPNP_C3 [BHGBH] 2015/05/18 09:23:47.477971 upnp.go:461: DEBUG: SOAP Action: [BHGBH] 2015/05/18 09:23:47.477971 upnp.go:462: DEBUG: SOAP Request:

<?xml version="1.0" ?>
<s:Envelope xmlns:s="http://schemas.xmlsoap.org/soap/envelope/" s:encodingStyle="http://schemas.xmlsoap.org/soap/encoding/">
<s:Body><u:AddPortMapping xmlns:u="urn:schemas-upnp-org:service:WANIPConnection:1">
<NewRemoteHost></NewRemoteHost>
<NewExternalPort>57290</NewExternalPort>
<NewProtocol>TCP</NewProtocol>
<NewInternalPort>22000</NewInternalPort>
<NewInternalClient>192.168.1.6</NewInternalClient>
<NewEnabled>1</NewEnabled>
<NewPortMappingDescription>syncthing-57290</NewPortMappingDescription>
<NewLeaseDuration>3600</NewLeaseDuration>
</u:AddPortMapping></s:Body>
</s:Envelope>

[BHGBH] 2015/05/18 09:23:47.481971 upnp.go:475: DEBUG: SOAP Response:

<s:Envelope xmlns:s=“http://schemas.xmlsoap.org/soap/envelope/” s:encodingStyle=“http://schemas.xmlsoap.org/soap/encoding/”>

<s:Body>

<s:Fault>

s:Client

UPnPError

725

OnlyPermanentLeasesSupported

</s:Fault>

</s:Body>

</s:Envelope>

[BHGBH] 2015/05/18 09:23:47.481971 upnp.go:460: DEBUG: SOAP Request URL: http://192.168.1.1:5000/Public_UPNP_C3 [BHGBH] 2015/05/18 09:23:47.481971 upnp.go:461: DEBUG: SOAP Action: [BHGBH] 2015/05/18 09:23:47.481971 upnp.go:462: DEBUG: SOAP Request:

<?xml version="1.0" ?>
<s:Envelope xmlns:s="http://schemas.xmlsoap.org/soap/envelope/" s:encodingStyle="http://schemas.xmlsoap.org/soap/encoding/">
<s:Body><u:AddPortMapping xmlns:u="urn:schemas-upnp-org:service:WANIPConnection:1">
<NewRemoteHost></NewRemoteHost>
<NewExternalPort>37341</NewExternalPort>
<NewProtocol>TCP</NewProtocol>
<NewInternalPort>22000</NewInternalPort>
<NewInternalClient>192.168.1.6</NewInternalClient>
<NewEnabled>1</NewEnabled>
<NewPortMappingDescription>syncthing-37341</NewPortMappingDescription>
<NewLeaseDuration>3600</NewLeaseDuration>
</u:AddPortMapping></s:Body>
</s:Envelope>

[BHGBH] 2015/05/18 09:23:47.485972 upnp.go:475: DEBUG: SOAP Response:

<s:Envelope xmlns:s=“http://schemas.xmlsoap.org/soap/envelope/” s:encodingStyle=“http://schemas.xmlsoap.org/soap/encoding/”>

<s:Body>

<s:Fault>

s:Client

UPnPError

725

OnlyPermanentLeasesSupported

</s:Fault>

</s:Body>

</s:Envelope>

[BHGBH] 2015/05/18 09:23:47.485972 upnpsvc.go:74: WARNING: Failed to set UPnP port mapping: external port 0 on device ‘WNDR4500 (Gateway)’ (192.168.1.1). [BHGBH] 2015/05/18 09:23:53.287303 connections.go:176: INFO: Established secure connection to LP75RYS-OYBFMRF-XZR4Y3W-NXZW4Y4-UGVX64H-IUIFRXL-OEHVP33-55K4IQP at 192.168.1.6:54253-192.168.1.2:22000 [BHGBH] 2015/05/18 09:23:53.288304 model.go:599: INFO: Device LP75RYS-OYBFMRF-XZR4Y3W-NXZW4Y4-UGVX64H-IUIFRXL-OEHVP33-55K4IQP client is “syncthing v0.11.5” [BHGBH] 2015/05/18 09:23:53.288304 model.go:604: INFO: Device LP75RYS-OYBFMRF-XZR4Y3W-NXZW4Y4-UGVX64H-IUIFRXL-OEHVP33-55K4IQP name is “SERVER” [BHGBH] 2015/05/18 09:24:00.107694 sharedpullerstate.go:165: INFO: Puller (folder “KamS”, file “.sync\ID”): dst stat dir: GetFileAttributesEx \?\C:\Users\Leni\KamS.sync: The system cannot find the file specified. [BHGBH] 2015/05/18 09:24:00.107694 sharedpullerstate.go:165: INFO: Puller (folder “KamS”, file “.sync\IgnoreList”): dst stat dir: GetFileAttributesEx \?\C:\Users\Leni\KamS.sync: The system cannot find the file specified. [BHGBH] 2015/05/18 09:24:00.107694 sharedpullerstate.go:165: INFO: Puller (folder “KamS”, file “.sync\StreamsList”): dst stat dir: GetFileAttributesEx \?\C:\Users\Leni\KamS.sync: The system cannot find the file specified. [BHGBH] 2015/05/18 09:24:00.107694 sharedpullerstate.go:165: INFO: Puller (folder “KamS”, file “_SYNCAPP\metadata.xml”): dst stat dir: GetFileAttributesEx \?\C:\Users\Leni\KamS_SYNCAPP: The system cannot find the file specified. [BHGBH] 2015/05/18 09:24:00.113694 sharedpullerstate.go:165: INFO: Puller (folder “KamS”, file “.sync\ID”): dst stat dir: GetFileAttributesEx \?\C:\Users\Leni\KamS.sync: The system cannot find the file specified. [BHGBH] 2015/05/18 09:24:00.113694 sharedpullerstate.go:165: INFO: Puller (folder “KamS”, file “.sync\StreamsList”): dst stat dir: GetFileAttributesEx \?\C:\Users\Leni\KamS.sync: The system cannot find the file specified. [BHGBH] 2015/05/18 09:24:00.114694 sharedpullerstate.go:165: INFO: Puller (folder “KamS”, file “.sync\IgnoreList”): dst stat dir: GetFileAttributesEx \?\C:\Users\Leni\KamS.sync: The system cannot find the file specified. [BHGBH] 2015/05/18 09:24:00.114694 sharedpullerstate.go:165: INFO: Puller (folder “KamS”, file “_SYNCAPP\metadata.xml”): dst stat dir: GetFileAttributesEx \?\C:\Users\Leni\KamS_SYNCAPP: The system cannot find the file specified. [BHGBH] 2015/05/18 09:24:00.127695 sharedpullerstate.go:165: INFO: Puller (folder “KamS”, file “.sync\IgnoreList”): dst stat dir: GetFileAttributesEx \?\C:\Users\Leni\KamS.sync: The system cannot find the file specified. [BHGBH] 2015/05/18 09:24:00.127695 sharedpullerstate.go:165: INFO: Puller (folder “KamS”, file “.sync\ID”): dst stat dir: GetFileAttributesEx \?\C:\Users\Leni\KamS.sync: The system cannot find the file specified. [BHGBH] 2015/05/18 09:24:00.127695 sharedpullerstate.go:165: INFO: Puller (folder “KamS”, file “.sync\StreamsList”): dst stat dir: GetFileAttributesEx \?\C:\Users\Leni\KamS.sync: The system cannot find the file specified. [BHGBH] 2015/05/18 09:24:00.127695 sharedpullerstate.go:165: INFO: Puller (folder “KamS”, file “_SYNCAPP\metadata.xml”): dst stat dir: GetFileAttributesEx \?\C:\Users\Leni\KamS_SYNCAPP: The system cannot find the file specified. [BHGBH] 2015/05/18 09:24:00.140695 sharedpullerstate.go:165: INFO: Puller (folder “KamS”, file “_SYNCAPP\metadata.xml”): dst stat dir: GetFileAttributesEx \?\C:\Users\Leni\KamS_SYNCAPP: The system cannot find the file specified. [BHGBH] 2015/05/18 09:24:00.140695 sharedpullerstate.go:165: INFO: Puller (folder “KamS”, file “.sync\IgnoreList”): dst stat dir: GetFileAttributesEx \?\C:\Users\Leni\KamS.sync: The system cannot find the file specified. [BHGBH] 2015/05/18 09:24:00.140695 sharedpullerstate.go:165: INFO: Puller (folder “KamS”, file “.sync\ID”): dst stat dir: GetFileAttributesEx \?\C:\Users\Leni\KamS.sync: The system cannot find the file specified. [BHGBH] 2015/05/18 09:24:00.140695 sharedpullerstate.go:165: INFO: Puller (folder “KamS”, file “.sync\StreamsList”): dst stat dir: GetFileAttributesEx \?\C:\Users\Leni\KamS.sync: The system cannot find the file specified. [BHGBH] 2015/05/18 09:24:00.154696 sharedpullerstate.go:165: INFO: Puller (folder “KamS”, file “.sync\IgnoreList”): dst stat dir: GetFileAttributesEx \?\C:\Users\Leni\KamS.sync: The system cannot find the file specified. [BHGBH] 2015/05/18 09:24:00.154696 sharedpullerstate.go:165: INFO: Puller (folder “KamS”, file “.sync\StreamsList”): dst stat dir: GetFileAttributesEx \?\C:\Users\Leni\KamS.sync: The system cannot find the file specified. [BHGBH] 2015/05/18 09:24:00.154696 sharedpullerstate.go:165: INFO: Puller (folder “KamS”, file “_SYNCAPP\metadata.xml”): dst stat dir: GetFileAttributesEx \?\C:\Users\Leni\KamS_SYNCAPP: The system cannot find the file specified. [BHGBH] 2015/05/18 09:24:00.154696 sharedpullerstate.go:165: INFO: Puller (folder “KamS”, file “.sync\ID”): dst stat dir: GetFileAttributesEx \?\C:\Users\Leni\KamS.sync: The system cannot find the file specified. [BHGBH] 2015/05/18 09:24:00.162697 sharedpullerstate.go:165: INFO: Puller (folder “KamS”, file “.sync\IgnoreList”): dst stat dir: GetFileAttributesEx \?\C:\Users\Leni\KamS.sync: The system cannot find the file specified. [BHGBH] 2015/05/18 09:24:00.163697 sharedpullerstate.go:165: INFO: Puller (folder “KamS”, file “.sync\ID”): dst stat dir: GetFileAttributesEx \?\C:\Users\Leni\KamS.sync: The system cannot find the file specified. [BHGBH] 2015/05/18 09:24:00.163697 sharedpullerstate.go:165: INFO: Puller (folder “KamS”, file “.sync\StreamsList”): dst stat dir: GetFileAttributesEx \?\C:\Users\Leni\KamS.sync: The system cannot find the file specified. [BHGBH] 2015/05/18 09:24:00.163697 sharedpullerstate.go:165: INFO: Puller (folder “KamS”, file “_SYNCAPP\metadata.xml”): dst stat dir: GetFileAttributesEx \?\C:\Users\Leni\KamS_SYNCAPP: The system cannot find the file specified. [BHGBH] 2015/05/18 09:24:00.170697 sharedpullerstate.go:165: INFO: Puller (folder “KamS”, file “.sync\ID”): dst stat dir: GetFileAttributesEx \?\C:\Users\Leni\KamS.sync: The system cannot find the file specified. [BHGBH] 2015/05/18 09:24:00.170697 sharedpullerstate.go:165: INFO: Puller (folder “KamS”, file “.sync\StreamsList”): dst stat dir: GetFileAttributesEx \?\C:\Users\Leni\KamS.sync: The system cannot find the file specified. [BHGBH] 2015/05/18 09:24:00.170697 sharedpullerstate.go:165: INFO: Puller (folder “KamS”, file “_SYNCAPP\metadata.xml”): dst stat dir: GetFileAttributesEx \?\C:\Users\Leni\KamS_SYNCAPP: The system cannot find the file specified. [BHGBH] 2015/05/18 09:24:00.170697 sharedpullerstate.go:165: INFO: Puller (folder “KamS”, file “.sync\IgnoreList”): dst stat dir: GetFileAttributesEx \?\C:\Users\Leni\KamS.sync: The system cannot find the file specified. [BHGBH] 2015/05/18 09:24:00.178698 sharedpullerstate.go:165: INFO: Puller (folder “KamS”, file “_SYNCAPP\metadata.xml”): dst stat dir: GetFileAttributesEx \?\C:\Users\Leni\KamS_SYNCAPP: The system cannot find the file specified. [BHGBH] 2015/05/18 09:24:00.178698 sharedpullerstate.go:165: INFO: Puller (folder “KamS”, file “.sync\StreamsList”): dst stat dir: GetFileAttributesEx \?\C:\Users\Leni\KamS.sync: The system cannot find the file specified. [BHGBH] 2015/05/18 09:24:00.178698 sharedpullerstate.go:165: INFO: Puller (folder “KamS”, file “.sync\IgnoreList”): dst stat dir: GetFileAttributesEx \?\C:\Users\Leni\KamS.sync: The system cannot find the file specified. [BHGBH] 2015/05/18 09:24:00.178698 sharedpullerstate.go:165: INFO: Puller (folder “KamS”, file “.sync\ID”): dst stat dir: GetFileAttributesEx \?\C:\Users\Leni\KamS.sync: The system cannot find the file specified. [BHGBH] 2015/05/18 09:24:00.186698 sharedpullerstate.go:165: INFO: Puller (folder “KamS”, file “.sync\ID”): dst stat dir: GetFileAttributesEx \?\C:\Users\Leni\KamS.sync: The system cannot find the file specified. [BHGBH] 2015/05/18 09:24:00.186698 sharedpullerstate.go:165: INFO: Puller (folder “KamS”, file “.sync\IgnoreList”): dst stat dir: GetFileAttributesEx \?\C:\Users\Leni\KamS.sync: The system cannot find the file specified. [BHGBH] 2015/05/18 09:24:00.186698 sharedpullerstate.go:165: INFO: Puller (folder “KamS”, file “_SYNCAPP\metadata.xml”): dst stat dir: GetFileAttributesEx \?\C:\Users\Leni\KamS_SYNCAPP: The system cannot find the file specified. [BHGBH] 2015/05/18 09:24:00.186698 sharedpullerstate.go:165: INFO: Puller (folder “KamS”, file “.sync\StreamsList”): dst stat dir: GetFileAttributesEx \?\C:\Users\Leni\KamS.sync: The system cannot find the file specified. [BHGBH] 2015/05/18 09:24:00.193699 sharedpullerstate.go:165: INFO: Puller (folder “KamS”, file “.sync\IgnoreList”): dst stat dir: GetFileAttributesEx \?\C:\Users\Leni\KamS.sync: The system cannot find the file specified. [BHGBH] 2015/05/18 09:24:00.193699 sharedpullerstate.go:165: INFO: Puller (folder “KamS”, file “_SYNCAPP\metadata.xml”): dst stat dir: GetFileAttributesEx \?\C:\Users\Leni\KamS_SYNCAPP: The system cannot find the file specified. [BHGBH] 2015/05/18 09:24:00.193699 sharedpullerstate.go:165: INFO: Puller (folder “KamS”, file “.sync\ID”): dst stat dir: GetFileAttributesEx \?\C:\Users\Leni\KamS.sync: The system cannot find the file specified. [BHGBH] 2015/05/18 09:24:00.193699 sharedpullerstate.go:165: INFO: Puller (folder “KamS”, file “.sync\StreamsList”): dst stat dir: GetFileAttributesEx \?\C:\Users\Leni\KamS.sync: The system cannot find the file specified. [BHGBH] 2015/05/18 09:24:00.200699 sharedpullerstate.go:165: INFO: Puller (folder “KamS”, file “.sync\ID”): dst stat dir: GetFileAttributesEx \?\C:\Users\Leni\KamS.sync: The system cannot find the file specified. [BHGBH] 2015/05/18 09:24:00.200699 sharedpullerstate.go:165: INFO: Puller (folder “KamS”, file “.sync\StreamsList”): dst stat dir: GetFileAttributesEx \?\C:\Users\Leni\KamS.sync: The system cannot find the file specified. [BHGBH] 2015/05/18 09:24:00.200699 sharedpullerstate.go:165: INFO: Puller (folder “KamS”, file “_SYNCAPP\metadata.xml”): dst stat dir: GetFileAttributesEx \?\C:\Users\Leni\KamS_SYNCAPP: The system cannot find the file specified. [BHGBH] 2015/05/18 09:24:00.200699 sharedpullerstate.go:165: INFO: Puller (folder “KamS”, file “.sync\IgnoreList”): dst stat dir: GetFileAttributesEx \?\C:\Users\Leni\KamS.sync: The system cannot find the file specified. [BHGBH] 2015/05/18 09:24:00.200699 rwfolder.go:237: WARNING: Folder “KamS” isn’t making progress - check logs for possible root cause. Pausing puller for 1m0s.

You should open config.xml in syncthing’s home folder and change upnpLeaseMinutes to 30.

Sorry, set it to 0, and post logs if it still doesn’t work.

OK set it to 0, message still koming, here is the log

[BHGBH] 2015/05/18 16:51:49.012210 main.go:466: INFO: syncthing v0.11.5 (go1.4.2 windows-amd64 default) unknown-user@syncthing-builder 2015-05-15 08:46:47 UTC
[BHGBH] 2015/05/18 16:51:49.016211 main.go:467: INFO: My ID: BHGBHX2-5BWXI2P-FEH5NTT-5W5JXBF-JQFGQ7H-7LOPDDR-R65LEVD-HY5BCQX
[BHGBH] 2015/05/18 16:51:49.021211 main.go:740: INFO: Database block cache capacity 63300 KiB
[BHGBH] 2015/05/18 16:51:50.570300 main.go:795: INFO: Starting web GUI on http://127.0.0.1:8384/
[BHGBH] 2015/05/18 16:51:52.816428 main.go:870: INFO: Starting local discovery announcements
[BHGBH] 2015/05/18 16:51:52.822428 discover.go:131: INFO: Local discovery over IPv6 unavailable
[BHGBH] 2015/05/18 16:51:52.822428 main.go:875: INFO: Starting global discovery announcements
[BHGBH] 2015/05/18 16:51:52.826429 main.go:646: OK: Ready to synchronize Bilder (read-write)
[BHGBH] 2015/05/18 16:51:52.826429 main.go:646: OK: Ready to synchronize Richard (read-write)
[BHGBH] 2015/05/18 16:51:52.826429 main.go:646: OK: Ready to synchronize SProfil (read-write)
[BHGBH] 2015/05/18 16:51:52.826429 main.go:646: OK: Ready to synchronize KamR (read-write)
[BHGBH] 2015/05/18 16:51:52.826429 main.go:646: OK: Ready to synchronize Musik (read-write)
[BHGBH] 2015/05/18 16:51:52.826429 main.go:646: OK: Ready to synchronize KamS (read-write)
[BHGBH] 2015/05/18 16:51:52.826429 main.go:646: OK: Ready to synchronize WaRB (read-write)
[BHGBH] 2015/05/18 16:51:52.826429 main.go:646: OK: Ready to synchronize WaRV (read-write)
[BHGBH] 2015/05/18 16:51:52.826429 main.go:646: OK: Ready to synchronize 2015 (read-write)
[BHGBH] 2015/05/18 16:51:52.826429 main.go:646: OK: Ready to synchronize Dokumente (read-write)
[BHGBH] 2015/05/18 16:51:52.826429 main.go:646: OK: Ready to synchronize WaSV (read-write)
[BHGBH] 2015/05/18 16:51:52.826429 main.go:646: OK: Ready to synchronize Wichtig (read-write)
[BHGBH] 2015/05/18 16:51:52.826429 main.go:646: OK: Ready to synchronize Videos_Privat (read-write)
[BHGBH] 2015/05/18 16:51:52.826429 main.go:646: OK: Ready to synchronize WaSB (read-write)
[BHGBH] 2015/05/18 16:51:52.827429 main.go:662: INFO: Device BHGBHX2-5BWXI2P-FEH5NTT-5W5JXBF-JQFGQ7H-7LOPDDR-R65LEVD-HY5BCQX is "Leni" at [dynamic]
[BHGBH] 2015/05/18 16:51:52.827429 main.go:662: INFO: Device LP75RYS-OYBFMRF-XZR4Y3W-NXZW4Y4-UGVX64H-IUIFRXL-OEHVP33-55K4IQP is "Server" at [dynamic]
[BHGBH] 2015/05/18 16:51:52.827429 main.go:662: INFO: Device NICMCM3-NSXK7FL-32TFLJO-AIXOELQ-A2OGDF5-KNVKJXI-ZJCNW3U-45RGSQE is "Handy Ric" at [dynamic]
[BHGBH] 2015/05/18 16:51:52.827429 main.go:662: INFO: Device RRW7XTO-4FHQU4K-JDYJRSU-IZT3GK4-PMRAGOA-V3DF6GS-NBPS6OA-ZWZZPQA is "Handy Syli" at [dynamic]
[BHGBH] 2015/05/18 16:51:52.827429 usage_report.go:144: INFO: Starting usage reporting
[BHGBH] 2015/05/18 16:51:52.829429 upnp.go:171: DEBUG: Starting discovery of device type urn:schemas-upnp-org:device:InternetGatewayDevice:1 on {B096932C-A245-4F1E-B974-2C6583964162}
[BHGBH] 2015/05/18 16:51:52.831429 upnp.go:190: DEBUG: Sending search request for device type urn:schemas-upnp-org:device:InternetGatewayDevice:1 on {B096932C-A245-4F1E-B974-2C6583964162}
[BHGBH] 2015/05/18 16:51:52.831429 upnp.go:171: DEBUG: Starting discovery of device type urn:schemas-upnp-org:device:InternetGatewayDevice:2 on {B096932C-A245-4F1E-B974-2C6583964162}
[BHGBH] 2015/05/18 16:51:52.833429 upnp.go:190: DEBUG: Sending search request for device type urn:schemas-upnp-org:device:InternetGatewayDevice:2 on {B096932C-A245-4F1E-B974-2C6583964162}
[BHGBH] 2015/05/18 16:51:52.845430 upnp.go:200: DEBUG: Listening for UPnP response for device type urn:schemas-upnp-org:device:InternetGatewayDevice:1 on {B096932C-A245-4F1E-B974-2C6583964162}
[BHGBH] 2015/05/18 16:51:52.845430 upnp.go:200: DEBUG: Listening for UPnP response for device type urn:schemas-upnp-org:device:InternetGatewayDevice:2 on {B096932C-A245-4F1E-B974-2C6583964162}
[BHGBH] 2015/05/18 16:51:52.847430 upnp.go:227: DEBUG: Handling UPnP response:

HTTP/1.1 200 OK

ST: urn:schemas-upnp-org:device:InternetGatewayDevice:1

LOCATION: http://192.168.1.1:5000/Public_UPNP_gatedesc.xml

SERVER: Linux/2.6.12, UPnP/1.0, NETGEAR-UPNP/1.0

EXT:

CACHE-CONTROL: max-age=3600

USN: uuid:656f09aa-320e-8a03-365e-af5f6f66a317::urn:schemas-upnp-org:device:InternetGatewayDevice:1




[BHGBH] 2015/05/18 16:51:52.864431 rwfolder.go:275: INFO: Completed initial scan (rw) of folder Richard
[BHGBH] 2015/05/18 16:51:52.865431 rwfolder.go:275: INFO: Completed initial scan (rw) of folder SProfil
[BHGBH] 2015/05/18 16:51:52.897433 rwfolder.go:275: INFO: Completed initial scan (rw) of folder Musik
[BHGBH] 2015/05/18 16:51:52.905433 rwfolder.go:275: INFO: Completed initial scan (rw) of folder Wichtig
[BHGBH] 2015/05/18 16:51:52.946435 rwfolder.go:275: INFO: Completed initial scan (rw) of folder KamR
[BHGBH] 2015/05/18 16:51:53.017440 rwfolder.go:275: INFO: Completed initial scan (rw) of folder WaRB
[BHGBH] 2015/05/18 16:51:53.049441 rwfolder.go:275: INFO: Completed initial scan (rw) of folder KamS
[BHGBH] 2015/05/18 16:51:53.108445 rwfolder.go:275: INFO: Completed initial scan (rw) of folder WaRV
[BHGBH] 2015/05/18 16:51:53.124446 rwfolder.go:275: INFO: Completed initial scan (rw) of folder 2015
[BHGBH] 2015/05/18 16:51:53.136446 rwfolder.go:275: INFO: Completed initial scan (rw) of folder WaSV
[BHGBH] 2015/05/18 16:51:53.149447 rwfolder.go:275: INFO: Completed initial scan (rw) of folder WaSB
[BHGBH] 2015/05/18 16:51:53.204450 upnp.go:398: DEBUG: [http://192.168.1.1:5000/Public_UPNP_gatedesc.xml] Found urn:schemas-upnp-org:service:WANIPConnection:1 with URL http://192.168.1.1:5000/Public_UPNP_C3
[BHGBH] 2015/05/18 16:51:53.204450 upnp.go:398: DEBUG: [http://192.168.1.1:5000/Public_UPNP_gatedesc.xml] Found urn:schemas-upnp-org:service:WANPPPConnection:1 with URL http://192.168.1.1:5000/Public_UPNP_C5
[BHGBH] 2015/05/18 16:51:53.209451 upnp.go:122: DEBUG: UPnP discovery result 656f09aa-320e-8a03-365e-af5f6f66a317 with services:
[BHGBH] 2015/05/18 16:51:53.209451 upnp.go:124: DEBUG: * [urn:upnp-org:serviceId:WANIPConn1] http://192.168.1.1:5000/Public_UPNP_C3
[BHGBH] 2015/05/18 16:51:53.209451 upnp.go:124: DEBUG: * [urn:upnp-org:serviceId:WANPPPConn1] http://192.168.1.1:5000/Public_UPNP_C5
[BHGBH] 2015/05/18 16:51:53.361459 rwfolder.go:275: INFO: Completed initial scan (rw) of folder Videos_Privat
[BHGBH] 2015/05/18 16:51:53.627474 rwfolder.go:275: INFO: Completed initial scan (rw) of folder Dokumente
[BHGBH] 2015/05/18 16:51:56.460636 rwfolder.go:275: INFO: Completed initial scan (rw) of folder Bilder
[BHGBH] 2015/05/18 16:52:02.832001 upnp.go:221: DEBUG: Discovery for device type urn:schemas-upnp-org:device:InternetGatewayDevice:1 on {B096932C-A245-4F1E-B974-2C6583964162} finished.
[BHGBH] 2015/05/18 16:52:02.834001 upnp.go:221: DEBUG: Discovery for device type urn:schemas-upnp-org:device:InternetGatewayDevice:2 on {B096932C-A245-4F1E-B974-2C6583964162} finished.
[BHGBH] 2015/05/18 16:52:02.834001 upnp.go:460: DEBUG: SOAP Request URL: http://192.168.1.1:5000/Public_UPNP_C3
[BHGBH] 2015/05/18 16:52:02.834001 upnp.go:461: DEBUG: SOAP Action: 
[BHGBH] 2015/05/18 16:52:02.834001 upnp.go:462: DEBUG: SOAP Request:

<?xml version="1.0" ?>
    <s:Envelope xmlns:s="http://schemas.xmlsoap.org/soap/envelope/" s:encodingStyle="http://schemas.xmlsoap.org/soap/encoding/">
    <s:Body><u:AddPortMapping xmlns:u="urn:schemas-upnp-org:service:WANIPConnection:1">
    <NewRemoteHost></NewRemoteHost>
    <NewExternalPort>32945</NewExternalPort>
    <NewProtocol>TCP</NewProtocol>
    <NewInternalPort>22000</NewInternalPort>
    <NewInternalClient>192.168.1.6</NewInternalClient>
    <NewEnabled>1</NewEnabled>
    <NewPortMappingDescription>syncthing-32945</NewPortMappingDescription>
    <NewLeaseDuration>0</NewLeaseDuration>
    </u:AddPortMapping></s:Body>
    </s:Envelope>

[BHGBH] 2015/05/18 16:52:02.839001 upnp.go:475: DEBUG: SOAP Response:

<?xml version="1.0"?>

<s:Envelope xmlns:s="http://schemas.xmlsoap.org/soap/envelope/" s:encodingStyle="http://schemas.xmlsoap.org/soap/encoding/">

<s:Body>

<u:AddPortMappingResponse xmlns:u="urn:schemas-upnp-org:service:WANIPConnection:1"/>

</s:Body>

</s:Envelope>



[BHGBH] 2015/05/18 16:52:02.839001 upnp.go:460: DEBUG: SOAP Request URL: http://192.168.1.1:5000/Public_UPNP_C5
[BHGBH] 2015/05/18 16:52:02.840001 upnp.go:461: DEBUG: SOAP Action: 
[BHGBH] 2015/05/18 16:52:02.840001 upnp.go:462: DEBUG: SOAP Request:

<?xml version="1.0" ?>
    <s:Envelope xmlns:s="http://schemas.xmlsoap.org/soap/envelope/" s:encodingStyle="http://schemas.xmlsoap.org/soap/encoding/">
    <s:Body><u:AddPortMapping xmlns:u="urn:schemas-upnp-org:service:WANPPPConnection:1">
    <NewRemoteHost></NewRemoteHost>
    <NewExternalPort>32945</NewExternalPort>
    <NewProtocol>TCP</NewProtocol>
    <NewInternalPort>22000</NewInternalPort>
    <NewInternalClient>192.168.1.6</NewInternalClient>
    <NewEnabled>1</NewEnabled>
    <NewPortMappingDescription>syncthing-32945</NewPortMappingDescription>
    <NewLeaseDuration>0</NewLeaseDuration>
    </u:AddPortMapping></s:Body>
    </s:Envelope>

[BHGBH] 2015/05/18 16:52:02.983010 upnp.go:475: DEBUG: SOAP Response:

<?xml version="1.0"?>

<s:Envelope xmlns:s="http://schemas.xmlsoap.org/soap/envelope/" s:encodingStyle="http://schemas.xmlsoap.org/soap/encoding/">

<s:Body>

<u:AddPortMappingResponse xmlns:u="urn:schemas-upnp-org:service:WANPPPConnection:1"/>

</s:Body>

</s:Envelope>



[BHGBH] 2015/05/18 16:52:02.983010 upnpsvc.go:81: INFO: New UPnP port mapping: external port 32945 to local port 22000.
[BHGBH] 2015/05/18 16:52:24.739254 connections.go:176: INFO: Established secure connection to LP75RYS-OYBFMRF-XZR4Y3W-NXZW4Y4-UGVX64H-IUIFRXL-OEHVP33-55K4IQP at 192.168.1.6:58194-192.168.1.2:22000
[BHGBH] 2015/05/18 16:52:24.740254 model.go:599: INFO: Device LP75RYS-OYBFMRF-XZR4Y3W-NXZW4Y4-UGVX64H-IUIFRXL-OEHVP33-55K4IQP client is "syncthing v0.11.5"
[BHGBH] 2015/05/18 16:52:24.741254 model.go:604: INFO: Device LP75RYS-OYBFMRF-XZR4Y3W-NXZW4Y4-UGVX64H-IUIFRXL-OEHVP33-55K4IQP name is "SERVER"
[BHGBH] 2015/05/18 16:53:28.579905 connections.go:176: INFO: Established secure connection to RRW7XTO-4FHQU4K-JDYJRSU-IZT3GK4-PMRAGOA-V3DF6GS-NBPS6OA-ZWZZPQA at 192.168.1.6:58200-192.168.1.4:22000
[BHGBH] 2015/05/18 16:53:28.580905 model.go:599: INFO: Device RRW7XTO-4FHQU4K-JDYJRSU-IZT3GK4-PMRAGOA-V3DF6GS-NBPS6OA-ZWZZPQA client is "syncthing v0.11.5"
[BHGBH] 2015/05/18 16:53:28.580905 model.go:604: INFO: Device RRW7XTO-4FHQU4K-JDYJRSU-IZT3GK4-PMRAGOA-V3DF6GS-NBPS6OA-ZWZZPQA name is "localhost"

Now it’s just refusing to create a mapping, no idea why, and it doesn’t provide any errors. Double check that UPnP is enabled, or contact your router vendor.

I am getting this also. v0.12.7 is fine (so using that), started in 0.12.8 and continues in 0.12.9

What OS?

There’s no difference in the UPnP code between those versions; however depending on the OS there may be a compiler difference in v0.12.9 - v0.12.7 and v0.12.8 are compiled the same though. Double check your firewall?

Windows 7 Ultimate. No amount of fiddling with anything will get a result. The router only has on/off for upnp, the software firewall is set to allow all. Which both of these do correctly for 0.12.7 but no later.

OK, there is actually a small difference in the UPnP code between v0.12.7 and v0.12.8. Can you open up a command prompt, and run the following (using v0.12.8, which doesn’t work):

C:\> SET STTRACE=upnp
C:\> syncthing > syncthing-log.txt

You may need to cd to the directory where syncthing is installed.

Let it run for maybe a minute, then post the log somewhere?

Here is 0.12.8 http://home.exetel.com.au/remote/syncthing-log0128.txt

Change to 0127 for the 0.12.7 log if it helps

The device is returning code 500/501, which is “FAULT_DEVICE_INTERNAL_ERROR”. It doesn’t say anything else, but that error code basically means something went wrong in the router. I suggest logging in to the router, removing any existing port forwards for Syncthing and trying again.

Hmmm… I didn’t have any ports forwarded. SO I set up a rule, tried again, then removed the rule and tried. All to no avail.

Oh well, something peculiar with my setup perhaps. Bit of a conundrum that it does work with the older version though.

Does it reliably work with the older version?

I’ve encountered the same error in the v0.12.9, though not in the previous ones.

It’s not a big deal for my setup, though annoying to have click that box.

I’m running Syncthing on an odroid xu4 with ubuntu server

It always successfully opens a port, I do get “An established connection was aborted by the software in your host machine.” errors from time to time. Since I’m usually not actually there watching what is going on, I can’t say what effect these errors have.

I too am having this issue from my Win7 machine. Once the machine has been left for while I can come back to a syncthing gui with half a dozen failed Upnp messages. This has only been with the last version or two, and my router and it’s config have not changed.