global@https://<domain>: Post https://<domain>: remote error: tls: illegal parameter

I have my own private discovery server, but if I enter this into my client it errors with:

global@https://<domain>: Post https://<domain>: remote error: tls: illegal parameter

Reverse proxy

stdiscosrv cmd: stdiscosrv -listen=:22068 -http

Apache reverse proxy (excerpt):

Include includes/ssl.conf  # Configures ssl certificates, etc.
SSLProtocol TLSv1.3              

ProxyPreserveHost On
ProxyRequests Off

RemoteIPHeader X-Forwarded-For

SSLVerifyClient optional_no_ca

RequestHeader set X-SSL-Cert "%{SSL_CLIENT_CERT}s"
RequestHeader set X-Forwarded-Proto "https"

ProxyPass / http://localhost:22068/
ProxyPassReverse / http://localhost:22068/

The apache docs describe SSL_CLIENT_CERT: https://httpd.apache.org/docs/2.4/mod/mod_ssl.html#envvars

And it logs this (in the access log):

<redacted> - - [09/Aug/2019:00:21:49 +0200] "GET /?device=<redacted> HTTP/1.1" 404 5424 "-" "Go-http-client/1.1"

But no error. It seems to kind of work, because the stats show devices:

The discovery serve logs show no error:

Aug 08 23:13:53 <redacted> systemd[1]: Started Syncthing Discovery Server.
Aug 08 23:13:54 <redacted> stdiscosrv[1220]: stdiscosrv v1.0.1 (go1.11.5 linux-amd64) deb@build.syncthing.net 2019-01-18 10:34:18 UTC
Aug 08 23:13:54 <redacted> stdiscosrv[1220]: Server device ID is <redacted>

Inspecting the headers that the backend gets

Using a test server that just logs the headers

With curl and random client cert:

User-Agent: curl/7.58.0
Accept: */*
X-SSL-Cert: -----BEGIN CERTIFICATE----- <redacted> -----END CERTIFICATE----- 
X-Forwarded-Proto: https
X-Forwarded-For: <redacted>
X-Forwarded-Host: <redacted>
X-Forwarded-Server: <redacted>
Connection: Keep-Alive

With syncthing:

User-Agent: Go-http-client/1.1
Accept-Encoding: gzip
X-SSL-Cert: (null)
X-Forwarded-Proto: https
X-Forwarded-For: <redacted>
X-Forwarded-Host: <redacted>
X-Forwarded-Server: <redacted>
Connection: Keep-Alive

So it looks like syncthing doesn’t send a client cert, but it is required to work correctly

Version Information

Syncthing Version: v1.2.1 (latest deb)
Stdiscosrv Version: v1.0.1 (latest deb)
OS Version: Ubuntu 18.04
Browser Version: N/A

This might be a problem, but it’s also a question of what you’re looking at. Syncthing doesn’t do the client cert dance for lookups, only for the announcements. That is, GET requests won’t get the cert while POST requests should have. On the client side there are options noannounce and nolookup that we use in the default setup, make sure you don’t if you use the same address for both.

You can run with STTRACE=discover to get more info from Syncthing on precisely what happens in the discovery code, maybe that’ll give you more detail on what it’s doing when it gets the remote error thing.

I guess you could also add some verbosity on the Apache side to see what it thinks is the illegal parameter, exactly.

Here are the logs:

[monitor] 2019/08/09 10:14:32.224880 monitor.go:102: INFO: Starting syncthing
[start] 2019/08/09 10:14:32.246918 main.go:557: INFO: syncthing v1.2.1 "Fermium Flea" (go1.12.7 linux-amd64) deb@build.syncthing.net 2019-07-27 18:36:33 UTC
[XWL3T] 2019/08/09 10:14:32.672533 syncthing.go:149: INFO: My ID: <redacted>
[XWL3T] 2019/08/09 10:14:33.579754 sha256.go:92: INFO: Single thread SHA256 performance is 293 MB/s using minio/sha256-simd (285 MB/s using crypto/sha256).
[XWL3T] 2019/08/09 10:14:34.056723 syncthing.go:181: INFO: Hashing performance is 253.13 MB/s
[XWL3T] 2019/08/09 10:14:34.057245 model.go:246: INFO: Ready to synchronize "<redacted>" (<redacted>) (sendreceive)
[XWL3T] 2019/08/09 10:14:34.057348 model.go:246: INFO: Ready to synchronize "Sync" (default) (sendreceive)
[XWL3T] 2019/08/09 10:14:34.057530 model.go:246: INFO: Ready to synchronize "<redacted>" (<redacted>) (sendreceive)
[XWL3T] 2019/08/09 10:14:34.057628 limiter.go:161: INFO: Overall send rate is unlimited, receive rate is unlimited
[XWL3T] 2019/08/09 10:14:34.057730 syncthing.go:275: INFO: Using discovery server https://<redacted>
[XWL3T] 2019/08/09 10:14:34.062864 relay_listen.go:65: INFO: Relay listener (relay://<redacted>:22067) starting
[XWL3T] 2019/08/09 10:14:34.064198 folder.go:559: INFO: Completed initial scan of sendreceive folder "Sync" (default)
[XWL3T] 2019/08/09 10:14:34.064998 global.go:237: DEBUG: Announcement: {"addresses":["relay://cromefire.myds.me:22067","tcp://:22000"]}
[XWL3T] 2019/08/09 10:14:34.066125 api.go:343: INFO: GUI and API listening on 127.0.0.1:8384
[XWL3T] 2019/08/09 10:14:34.066156 api.go:344: INFO: Access the GUI via the following URL: http://127.0.0.1:8384/
[XWL3T] 2019/08/09 10:14:34.066249 tcp_listen.go:59: INFO: TCP listener ([::]:22000) starting
[XWL3T] 2019/08/09 10:14:34.066279 syncthing.go:336: INFO: My name is "tpu"
[XWL3T] 2019/08/09 10:14:34.066305 syncthing.go:339: INFO: Device <redacted> is "<redacted>" at [<redacted> dynamic]
[XWL3T] 2019/08/09 10:14:34.066324 syncthing.go:339: INFO: <redacted> is "<redacted>" at [dynamic]
[XWL3T] 2019/08/09 10:14:34.066340 syncthing.go:339: INFO: Device <redacted> is "<redacted>" at [tcp://<redacted>:22000 dynamic]
[XWL3T] 2019/08/09 10:14:34.066356 syncthing.go:339: INFO: Device <redacted> is "<redacted>" at [tcp://<redacted>:22000 dynamic]
[XWL3T] 2019/08/09 10:14:34.109768 folder.go:559: INFO: Completed initial scan of sendreceive folder "<redacted>" (<redacted>)
[XWL3T] 2019/08/09 10:14:34.174824 global.go:163: DEBUG: globalClient.Lookup https://<redacted>?device=<redacted> 404 Not Found
[XWL3T] 2019/08/09 10:14:34.174866 cache.go:128: DEBUG: lookup results for <redacted>
[XWL3T] 2019/08/09 10:14:34.174877 cache.go:129: DEBUG:   addresses:  []
[XWL3T] 2019/08/09 10:14:34.179019 static.go:65: INFO: Joined relay relay://<redacted>:22067
[XWL3T] 2019/08/09 10:14:34.182172 global.go:241: DEBUG: announce POST: Post https://<redacted>: remote error: tls: illegal parameter
[XWL3T] 2019/08/09 10:14:37.328175 global.go:163: DEBUG: globalClient.Lookup https://<redacted>?device=<redacted> 404 Not Found
[XWL3T] 2019/08/09 10:14:37.328278 cache.go:128: DEBUG: lookup results for <redacted>
[XWL3T] 2019/08/09 10:14:37.328293 cache.go:129: DEBUG:   addresses:  []
[XWL3T] 2019/08/09 10:14:37.350012 global.go:163: DEBUG: globalClient.Lookup https://<redacted>?device=<redacted> 404 Not Found
[XWL3T] 2019/08/09 10:14:37.350058 cache.go:128: DEBUG: lookup results for <redacted>
[XWL3T] 2019/08/09 10:14:37.350069 cache.go:129: DEBUG:   addresses:  []
[XWL3T] 2019/08/09 10:14:37.366250 global.go:163: DEBUG: globalClient.Lookup https://<redacted>?device=<redacted> 404 Not Found
[XWL3T] 2019/08/09 10:14:37.366411 cache.go:128: DEBUG: lookup results for <redacted>
[XWL3T] 2019/08/09 10:14:37.366452 cache.go:129: DEBUG:   addresses:  []
[XWL3T] 2019/08/09 10:14:37.500492 service.go:319: INFO: Established secure connection to <redacted> at <redacted>:37214-<redacted>:22000/tcp-client/TLS1.2-TLS_ECDHE_ECDSA_WITH_AES_256_GCM_SHA384
[XWL3T] 2019/08/09 10:14:37.500665 model.go:1860: INFO: Device <redacted> client is "syncthing v1.2.1" named "<redacted>" at <redacted>:37214-<redacted>:22000/tcp-client/TLS1.2-TLS_ECDHE_ECDSA_WITH_AES_256_GCM_SHA384
[XWL3T] 2019/08/09 10:14:38.500204 cache.go:94: DEBUG: negative cache entry for <redacted> at global@https://<redacted> valid until 2019-08-09 10:15:34.174851845 +0200 CEST m=+61.948401005 or 2019-08-09 10:31:19.174852799 +0200 CEST m=+1006.948401956
[XWL3T] 2019/08/09 10:14:38.500253 cache.go:128: DEBUG: lookup results for <redacted>
[XWL3T] 2019/08/09 10:14:38.500263 cache.go:129: DEBUG:   addresses:  []
[XWL3T] 2019/08/09 10:14:38.500380 cache.go:94: DEBUG: negative cache entry for <redacted> at global@https://<redacted> valid until 2019-08-09 10:15:37.328265453 +0200 CEST m=+65.101814648 or 2019-08-09 10:25:45.328266275 +0200 CEST m=+673.101815445
[XWL3T] 2019/08/09 10:14:38.500399 cache.go:128: DEBUG: lookup results for <redacted>
[XWL3T] 2019/08/09 10:14:38.500408 cache.go:129: DEBUG:   addresses:  []
[XWL3T] 2019/08/09 10:14:38.500513 cache.go:94: DEBUG: negative cache entry for <redacted> at global@https://<redacted> valid until 2019-08-09 10:15:37.350044006 +0200 CEST m=+65.123593173 or 2019-08-09 10:22:49.350044568 +0200 CEST m=+497.123593736
[XWL3T] 2019/08/09 10:14:38.500526 cache.go:128: DEBUG: lookup results for <redacted>
[XWL3T] 2019/08/09 10:14:38.500533 cache.go:129: DEBUG:   addresses:  []
[XWL3T] 2019/08/09 10:14:40.500932 cache.go:94: DEBUG: negative cache entry for <redacted> at global@https://<redacted> valid until 2019-08-09 10:15:34.174851845 +0200 CEST m=+61.948401005 or 2019-08-09 10:31:19.174852799 +0200 CEST m=+1006.948401956
[XWL3T] 2019/08/09 10:14:40.500979 cache.go:128: DEBUG: lookup results for <redacted>
[XWL3T] 2019/08/09 10:14:40.500989 cache.go:129: DEBUG:   addresses:  []
[XWL3T] 2019/08/09 10:14:40.501022 cache.go:94: DEBUG: negative cache entry for <redacted> at global@https://<redacted> valid until 2019-08-09 10:15:37.328265453 +0200 CEST m=+65.101814648 or 2019-08-09 10:25:45.328266275 +0200 CEST m=+673.101815445
[XWL3T] 2019/08/09 10:14:40.501035 cache.go:128: DEBUG: lookup results for <redacted>
[XWL3T] 2019/08/09 10:14:40.501042 cache.go:129: DEBUG:   addresses:  []
[XWL3T] 2019/08/09 10:14:40.501059 cache.go:94: DEBUG: negative cache entry for <redacted> at global@https://<redacted> valid until 2019-08-09 10:15:37.350044006 +0200 CEST m=+65.123593173 or 2019-08-09 10:22:49.350044568 +0200 CEST m=+497.123593736
[XWL3T] 2019/08/09 10:14:40.501071 cache.go:128: DEBUG: lookup results for MRHR2PC-7FV4SFY-GPDSGH7-BKF45FP-MQQM7ID-ZF3DBOX-HRS4HFC-55RAUAU
[XWL3T] 2019/08/09 10:14:40.501077 cache.go:129: DEBUG:   addresses:  []
[XWL3T] 2019/08/09 10:14:44.501437 cache.go:94: DEBUG: negative cache entry for <redacted> at global@https://<redacted> valid until 2019-08-09 10:15:34.174851845 +0200 CEST m=+61.948401005 or 2019-08-09 10:31:19.174852799 +0200 CEST m=+1006.948401956
[XWL3T] 2019/08/09 10:14:44.501479 cache.go:128: DEBUG: lookup results for <redacted>
[XWL3T] 2019/08/09 10:14:44.501488 cache.go:129: DEBUG:   addresses:  []
[XWL3T] 2019/08/09 10:14:44.501535 cache.go:94: DEBUG: negative cache entry for <redacted> at global@https://<redacted> valid until 2019-08-09 10:15:37.328265453 +0200 CEST m=+65.101814648 or 2019-08-09 10:25:45.328266275 +0200 CEST m=+673.101815445
[XWL3T] 2019/08/09 10:14:44.501549 cache.go:128: DEBUG: lookup results for <redacted>
[XWL3T] 2019/08/09 10:14:44.501556 cache.go:129: DEBUG:   addresses:  []
[XWL3T] 2019/08/09 10:14:44.501772 cache.go:94: DEBUG: negative cache entry for <redacted> at global@https://<redacted> valid until 2019-08-09 10:15:37.350044006 +0200 CEST m=+65.123593173 or 2019-08-09 10:22:49.350044568 +0200 CEST m=+497.123593736
[XWL3T] 2019/08/09 10:14:44.501787 cache.go:128: DEBUG: lookup results for <redacted>
[XWL3T] 2019/08/09 10:14:44.501808 cache.go:129: DEBUG:   addresses:  []
[XWL3T] 2019/08/09 10:14:45.177903 service.go:66: INFO: Detected 3 NAT services
[XWL3T] 2019/08/09 10:14:46.566512 folder.go:559: INFO: Completed initial scan of sendreceive folder "<redacted>" (<redacted>)
[XWL3T] 2019/08/09 10:14:52.502246 cache.go:94: DEBUG: negative cache entry for <redacted> at global@https://<redacted> valid until 2019-08-09 10:15:34.174851845 +0200 CEST m=+61.948401005 or 2019-08-09 10:31:19.174852799 +0200 CEST m=+1006.948401956
[XWL3T] 2019/08/09 10:14:52.502306 cache.go:128: DEBUG: lookup results for <redacted>
[XWL3T] 2019/08/09 10:14:52.502324 cache.go:129: DEBUG:   addresses:  []
[XWL3T] 2019/08/09 10:14:52.502449 cache.go:94: DEBUG: negative cache entry for <redacted> at global@https://<redacted> valid until 2019-08-09 10:15:37.328265453 +0200 CEST m=+65.101814648 or 2019-08-09 10:25:45.328266275 +0200 CEST m=+673.101815445
[XWL3T] 2019/08/09 10:14:52.502519 cache.go:128: DEBUG: lookup results for <redacted>
[XWL3T] 2019/08/09 10:14:52.502615 cache.go:129: DEBUG:   addresses:  []
[XWL3T] 2019/08/09 10:14:52.502769 cache.go:94: DEBUG: negative cache entry for <redacted> at global@https://<redacted> valid until 2019-08-09 10:15:37.350044006 +0200 CEST m=+65.123593173 or 2019-08-09 10:22:49.350044568 +0200 CEST m=+497.123593736
[XWL3T] 2019/08/09 10:14:52.502800 cache.go:128: DEBUG: lookup results for <redacted>
[XWL3T] 2019/08/09 10:14:52.502814 cache.go:129: DEBUG:   addresses:  []

I’m on a phone and I haven’t looked at this in great detail but I noted one thing:

Have you configured the TLS server to only allow TLS 1.3? Go apps compiled with Go <= 1.11 don’t speak that. Go 1.12 only speaks it when some debug environment variable is set.

A future version of Go (1.13) will have TLS 1.3 enabled by default.

The get requests work fine and I had it set to TLS 1.2 before

The error is reported by Apache. You should troubleshoot on that side to see what the actual error is.

I’m currently doing this

So even with max debug level (trace6) in apache I don’t see an apache error, but I see Connection closed to child 74 with abortive shutdown, which from my understanding means the thing proxied to just closed the tcp connection.

Is there a way to get debug info from stdiscosrv?

stdiscosrv -debug

The post request does not come through according to the log output

You’re running the discosrv with -http, right?

Yes as said GET requests work, I now think it might be some special case with apache an the client cert that causes it to abort

How would the url of one of the POST requests look like?

e.g. How can I craft one using curl

Post to the root URL with a JSON body, {"addresses":["tcp://0.0.0.0:22000"]} for example

Also, if its an option, switch to nginx as we know that works.

nginx is not possible because the deployment is a perfectly tuned setup with a lot of subdomains and services

Yeah it really looks like Apache is killing the connection on the POST. Can you somehow debug the TLS handshake, to see if there is an error (and where)? Packet inspection (Wireshark or similar) could be interesting, assuming the TLS handshake is what fails, and not something on the application layer.

I’ll try it with curl -v, but Wireshark is actually a great idea, if that does not work

curl works (executed inside ~/.config/syncthing):

~$ curl -v -X POST --cert cert.pem --key key.pem https://<redacted> -d '{"addresses":["tcp://0.0.0.0:22000"]}' -H "Content-Type: application/json"
Note: Unnecessary use of -X or --request, POST is already inferred.
* Rebuilt URL to: https://<redacted>/
*   Trying 91.63.83.36...
* TCP_NODELAY set
* Connected to <redacted> (91.63.83.36) port 443 (#0)
* ALPN, offering h2
* ALPN, offering http/1.1
* successfully set certificate verify locations:
*   CAfile: /etc/ssl/certs/ca-certificates.crt
  CApath: /etc/ssl/certs
* (304) (OUT), TLS handshake, Client hello (1):
* (304) (IN), TLS handshake, Server hello (2):
* (304) (IN), TLS Unknown, Certificate Status (22):
* (304) (IN), TLS handshake, Unknown (8):
* (304) (IN), TLS Unknown, Certificate Status (22):
* (304) (IN), TLS handshake, Request CERT (13):
* (304) (IN), TLS Unknown, Certificate Status (22):
* (304) (IN), TLS handshake, Certificate (11):
* (304) (IN), TLS Unknown, Certificate Status (22):
* (304) (IN), TLS handshake, CERT verify (15):
* (304) (IN), TLS Unknown, Certificate Status (22):
* (304) (IN), TLS handshake, Finished (20):
* (304) (OUT), TLS change cipher, Client hello (1):
* (304) (OUT), TLS Unknown, Certificate Status (22):
* (304) (OUT), TLS handshake, Certificate (11):
* (304) (OUT), TLS Unknown, Certificate Status (22):
* (304) (OUT), TLS handshake, CERT verify (15):
* (304) (OUT), TLS Unknown, Certificate Status (22):
* (304) (OUT), TLS handshake, Finished (20):
* SSL connection using unknown / TLS_AES_256_GCM_SHA384
* ALPN, server accepted to use h2
* Server certificate:
*  subject: CN=<redacted>
*  start date: Jul 16 08:47:53 2019 GMT
*  expire date: Oct 14 08:47:53 2019 GMT
*  subjectAltName: host "<redacted>" matched cert's "<redacted>"
*  issuer: C=US; O=Let's Encrypt; CN=Let's Encrypt Authority X3
*  SSL certificate verify ok.
* Using HTTP2, server supports multi-use
* Connection state changed (HTTP/2 confirmed)
* Copying HTTP/2 data in stream buffer to connection buffer after upgrade: len=0
* (304) (OUT), TLS Unknown, Unknown (23):
* (304) (OUT), TLS Unknown, Unknown (23):
* (304) (OUT), TLS Unknown, Unknown (23):
* Using Stream ID: 1 (easy handle 0x55ba0635f580)
* (304) (OUT), TLS Unknown, Unknown (23):
> POST / HTTP/2
> Host: <redacted>
> User-Agent: curl/7.58.0
> Accept: */*
> Content-Type: application/json
> Content-Length: 37
> 
* (304) (OUT), TLS Unknown, Unknown (23):
* We are completely uploaded and fine
* (304) (IN), TLS Unknown, Certificate Status (22):
* (304) (IN), TLS handshake, Newsession Ticket (4):
* (304) (IN), TLS Unknown, Certificate Status (22):
* (304) (IN), TLS handshake, Newsession Ticket (4):
* (304) (IN), TLS Unknown, Unknown (23):
* Connection state changed (MAX_CONCURRENT_STREAMS updated)!
* (304) (OUT), TLS Unknown, Unknown (23):
* (304) (IN), TLS Unknown, Unknown (23):
< HTTP/2 204 
< date: Fri, 09 Aug 2019 20:47:56 GMT
< server: Cromefire Web Frontend
< strict-transport-security: max-age=31536000; includeSubDomains; preload
< reannounce-after: 3354
< 
* Connection #0 to host <redacted> left intact

So I guess the error has to be in the specific (tls?) implementation of go / in the request code of syncthing

Also the restriction of max replies on the first day is a very poor UX