UPnP not happening

I am running 0.14.36 and have NAT Traversal enabled in the settings. The router syncthing is behind is UPnP enabled (other apps successfully use it that way). However, I can’t see anything in the logs about syncthing attempting to create UPnP port mapping. This is confirmed by checking the mapped ports with upnpc.

Any ideas on how I can get UPnP working?

Enable the upnp debug facility. In your version probably only through STTRACE env var, but I’d generally just upgrade first, which besides many other benefits will give you a log view in the web UI and we don’t actually debug ancient versions.

It probably fails to find upnp devices, potentially because of firewalls or network configuration.

Ok, I upgraded to 1.1.1 and enabled upnp debugging via the GUI. Don’t see anything in the logs yet besides:

2019-05-03 06:25:37 Detected 1 NAT service

How often will it attempt to create a port mapping?

Here are the logs:

2019-05-03 06:55:27 Starting discovery of device type urn:schemas-upnp-org:device:InternetGatewayDevice:1 on eth0
2019-05-03 06:55:27 Starting discovery of device type urn:schemas-upnp-org:device:InternetGatewayDevice:2 on eth0
2019-05-03 06:55:27 Sending search request for device type urn:schemas-upnp-org:device:InternetGatewayDevice:1 on eth0
2019-05-03 06:55:27 Sending search request for device type urn:schemas-upnp-org:device:InternetGatewayDevice:2 on eth0
2019-05-03 06:55:27 Listening for UPnP response for device type urn:schemas-upnp-org:device:InternetGatewayDevice:2 on eth0
2019-05-03 06:55:27 Listening for UPnP response for device type urn:schemas-upnp-org:device:InternetGatewayDevice:1 on eth0
2019-05-03 06:55:37 Discovery for device type urn:schemas-upnp-org:device:InternetGatewayDevice:2 on eth0 finished.
2019-05-03 06:55:37 Discovery for device type urn:schemas-upnp-org:device:InternetGatewayDevice:1 on eth0 finished.

I don’t think Syncthing logs created port mappings, so this is not a good basis for assuming port mappings don’t happen.

My basis is that checking the ports with the upnpc command does not show any that syncthing would use.

If you provided the full logs it might be more obvious.

Here are the full logs from the restart:

2019-05-05 16:03:25 syncthing v1.1.1 "Erbium Earthworm" (go1.11.5 linux-amd64) unknown-user@9b54055ad277 2019-04-16 18:39:31 UTC
2019-05-05 16:03:25 My ID: KTBACKG-ZALUFDI-QBZ77VB-JGL6P4F-7OOWJHE-XHBC7VB-WIKAXRX-BCUPYAS
2019-05-05 16:03:26 Single thread SHA256 performance is 316 MB/s using minio/sha256-simd (196 MB/s using crypto/sha256).
2019-05-05 16:03:27 Hashing performance is 272.71 MB/s
2019-05-05 16:03:28 Ready to synchronize "Default Folder" (default) (sendreceive)
2019-05-05 16:03:28 Ready to synchronize "radarr" (gndsh-mnvsv) (sendreceive)
2019-05-05 16:03:28 Ready to synchronize "sonarr" (zhhqc-nsznn) (sendreceive)
2019-05-05 16:03:28 Overall send rate is unlimited, receive rate is unlimited
2019-05-05 16:03:28 Using discovery server https://discovery-v4.syncthing.net/v2/?nolookup&id=LYXKCHX-VI3NYZR-ALCJBHF-WMZYSPK-QG6QJA3-MPFYMSO-U56GTUK-NA2MIAW
2019-05-05 16:03:28 Using discovery server https://discovery-v6.syncthing.net/v2/?nolookup&id=LYXKCHX-VI3NYZR-ALCJBHF-WMZYSPK-QG6QJA3-MPFYMSO-U56GTUK-NA2MIAW
2019-05-05 16:03:28 ...
2019-05-05 16:03:28 Using discovery server https://discovery.syncthing.net/v2/?noannounce&id=LYXKCHX-VI3NYZR-ALCJBHF-WMZYSPK-QG6QJA3-MPFYMSO-U56GTUK-NA2MIAW
2019-05-05 16:03:28 Completed initial scan of sendreceive folder "Default Folder" (default)
2019-05-05 16:03:28 TCP listener ([::]:22000) starting
2019-05-05 16:03:28 Relay listener (dynamic+https://relays.syncthing.net/endpoint) starting
2019-05-05 16:03:28 Completed initial scan of sendreceive folder "radarr" (gndsh-mnvsv)
2019-05-05 16:03:28 GUI and API listening on [::]:8384
2019-05-05 16:03:28 Access the GUI via the following URL: http://127.0.0.1:8384/
2019-05-05 16:03:28 My name is "plex-sync"
2019-05-05 16:03:28 Device PULDPYB-UCMUIQ7-IK6PVG6-IYABRWH-3WFGRXJ-2DJCJ2G-BLBOFAN-K5Q4LQG is "whatbox.ca" at [dynamic]
2019-05-05 16:03:28 Device XZTODMH-73XAN2I-T26WE7F-6TYW6MF-AQZKNF3-TVE35FB-H63SNEE-24SCOAP is "chadikins" at [dynamic]
2019-05-05 16:03:30 Completed initial scan of sendreceive folder "sonarr" (zhhqc-nsznn)
2019-05-05 16:03:31 Established secure connection to XZTODMH-73XAN2I-T26WE7F-6TYW6MF-AQZKNF3-TVE35FB-H63SNEE-24SCOAP at 172.17.0.3:36748-198.27.241.245:22000/tcp-client/TLS1.2-TLS_ECDHE_ECDSA_WITH_CHACHA20_POLY1305
2019-05-05 16:03:31 Device XZTODMH-73XAN2I-T26WE7F-6TYW6MF-AQZKNF3-TVE35FB-H63SNEE-24SCOAP client is "syncthing v0.14.54" named "298eaebc24e6" at 172.17.0.3:36748-198.27.241.245:22000/tcp-client/TLS1.2-TLS_ECDHE_ECDSA_WITH_CHACHA20_POLY1305
2019-05-05 16:03:48 Detected 1 NAT service
2019-05-05 16:04:02 Enabled debug data for "upnp"
2019-05-05 16:04:14 Joined relay relay://172.245.135.170:22067
2019-05-05 16:08:44 Established secure connection to PULDPYB-UCMUIQ7-IK6PVG6-IYABRWH-3WFGRXJ-2DJCJ2G-BLBOFAN-K5Q4LQG at 172.17.0.3:34108-172.245.135.170:22067/relay-server/TLS1.2-TLS_ECDHE_ECDSA_WITH_CHACHA20_POLY1305
2019-05-05 16:08:44 Device PULDPYB-UCMUIQ7-IK6PVG6-IYABRWH-3WFGRXJ-2DJCJ2G-BLBOFAN-K5Q4LQG client is "syncthing v1.1.1" named "whatbox.ca" at 172.17.0.3:34108-172.245.135.170:22067/relay-server/TLS1.2-TLS_ECDHE_ECDSA_WITH_CHACHA20_POLY1305

You enabled upnp logging after upnp discovery cycle has completed, so there is not much use out of these logs. I suggest you enable logging via an env var before startup.

Ok, after enabling STTRACE=upnp, here are the logs:

2019-05-07 07:35:15 syncthing v1.1.1 "Erbium Earthworm" (go1.11.5 linux-amd64) unknown-user@9b54055ad277 2019-04-16 18:39:31 UTC
2019-05-07 07:35:15 My ID: KTBACKG-ZALUFDI-QBZ77VB-JGL6P4F-7OOWJHE-XHBC7VB-WIKAXRX-BCUPYAS
2019-05-07 07:35:15 Single thread SHA256 performance is 315 MB/s using minio/sha256-simd (196 MB/s using crypto/sha256).
2019-05-07 07:35:16 Hashing performance is 272.12 MB/s
2019-05-07 07:35:17 Ready to synchronize "sonarr" (zhhqc-nsznn) (sendreceive)
2019-05-07 07:35:17 Ready to synchronize "Default Folder" (default) (sendreceive)
2019-05-07 07:35:17 Ready to synchronize "radarr" (gndsh-mnvsv) (sendreceive)
2019-05-07 07:35:17 Overall send rate is unlimited, receive rate is unlimited
2019-05-07 07:35:17 Using discovery server https://discovery-v4.syncthing.net/v2/?nolookup&id=LYXKCHX-VI3NYZR-ALCJBHF-WMZYSPK-QG6QJA3-MPFYMSO-U56GTUK-NA2MIAW
2019-05-07 07:35:17 Using discovery server https://discovery-v6.syncthing.net/v2/?nolookup&id=LYXKCHX-VI3NYZR-ALCJBHF-WMZYSPK-QG6QJA3-MPFYMSO-U56GTUK-NA2MIAW
2019-05-07 07:35:17 ...
2019-05-07 07:35:17 Using discovery server https://discovery.syncthing.net/v2/?noannounce&id=LYXKCHX-VI3NYZR-ALCJBHF-WMZYSPK-QG6QJA3-MPFYMSO-U56GTUK-NA2MIAW
2019-05-07 07:35:17 TCP listener ([::]:22000) starting
2019-05-07 07:35:17 Relay listener (dynamic+https://relays.syncthing.net/endpoint) starting
2019-05-07 07:35:17 Starting discovery of device type urn:schemas-upnp-org:device:InternetGatewayDevice:1 on eth0
2019-05-07 07:35:17 Sending search request for device type urn:schemas-upnp-org:device:InternetGatewayDevice:1 on eth0
2019-05-07 07:35:17 Listening for UPnP response for device type urn:schemas-upnp-org:device:InternetGatewayDevice:1 on eth0
2019-05-07 07:35:17 Starting discovery of device type urn:schemas-upnp-org:device:InternetGatewayDevice:2 on eth0
2019-05-07 07:35:17 Sending search request for device type urn:schemas-upnp-org:device:InternetGatewayDevice:2 on eth0
2019-05-07 07:35:17 Listening for UPnP response for device type urn:schemas-upnp-org:device:InternetGatewayDevice:2 on eth0
2019-05-07 07:35:17 Completed initial scan of sendreceive folder "Default Folder" (default)
2019-05-07 07:35:17 Completed initial scan of sendreceive folder "radarr" (gndsh-mnvsv)
2019-05-07 07:35:17 GUI and API listening on [::]:8384
2019-05-07 07:35:17 Access the GUI via the following URL: http://127.0.0.1:8384/
2019-05-07 07:35:17 My name is "plex-sync"
2019-05-07 07:35:17 Device PULDPYB-UCMUIQ7-IK6PVG6-IYABRWH-3WFGRXJ-2DJCJ2G-BLBOFAN-K5Q4LQG is "whatbox.ca" at [dynamic]
2019-05-07 07:35:17 Device XZTODMH-73XAN2I-T26WE7F-6TYW6MF-AQZKNF3-TVE35FB-H63SNEE-24SCOAP is "chadikins" at [dynamic]
2019-05-07 07:35:19 Established secure connection to XZTODMH-73XAN2I-T26WE7F-6TYW6MF-AQZKNF3-TVE35FB-H63SNEE-24SCOAP at 172.17.0.3:47148-198.27.241.245:22000/tcp-client/TLS1.2-TLS_ECDHE_ECDSA_WITH_CHACHA20_POLY1305
2019-05-07 07:35:19 Device XZTODMH-73XAN2I-T26WE7F-6TYW6MF-AQZKNF3-TVE35FB-H63SNEE-24SCOAP client is "syncthing v0.14.54" named "298eaebc24e6" at 172.17.0.3:47148-198.27.241.245:22000/tcp-client/TLS1.2-TLS_ECDHE_ECDSA_WITH_CHACHA20_POLY1305
2019-05-07 07:35:22 Completed initial scan of sendreceive folder "sonarr" (zhhqc-nsznn)
2019-05-07 07:35:27 Discovery for device type urn:schemas-upnp-org:device:InternetGatewayDevice:1 on eth0 finished.
2019-05-07 07:35:27 Discovery for device type urn:schemas-upnp-org:device:InternetGatewayDevice:2 on eth0 finished.
2019-05-07 07:35:37 Detected 1 NAT service
2019-05-07 07:35:51 Joined relay relay://199.181.238.100:22067

The UPnP router definitely works (confirmed with upnpc -l), but I’m thinking this is not working because the syncthing is running inside a Docker container…

Docker has it’s own networking, so it won’t work, it’s probably discovering something that is not your gateway.

You need to run with --net=host, also capture the logs from the console not the web ui as the logs in the web ui are partial.

1 Like

Yeah, running it with --net=host seemed to work, the NAT port mapping is now created. Thanks for your help.

This topic was automatically closed 30 days after the last reply. New replies are no longer allowed.