Cloudflared DoH 1.1.1.1 failed to perform an HTTPS request


#1

I’m running a cloudflared and Pi-Hole on Rasbian as described here, but keep getting cloudflared taking all the CPU and then DNS fails like so:

sudo systemctl status dnsproxy.service
● dnsproxy.service - CloudFlare DNS over HTTPS Proxy
   Loaded: loaded (/etc/systemd/system/dnsproxy.service; enabled; vendor preset: enabled)
   Active: active (running) since Tue 2018-04-24 21:36:38 UTC; 2min 53s ago
 Main PID: 1973 (cloudflared)
   CGroup: /system.slice/dnsproxy.service
           └─1973 /home/pi/argo-tunnel/cloudflared proxy-dns --port 54 --upstream https://1.1.1.1/.well-known/dns-query --upstream https://1.0.0.1/.well-known/dns-query

Apr 24 21:39:11 raspberrypi cloudflared[1973]: time="2018-04-24T21:39:11Z" level=error msg="failed to connect to an HTTPS backend \"https://1.1.1.1/.well-known/dns-query\"" error="failed to perform an HTTPS request: Post https://1.1.1.1/.well-known/dns-query: EOF"
Apr 24 21:39:11 raspberrypi cloudflared[1973]: time="2018-04-24T21:39:11Z" level=error msg="failed to connect to an HTTPS backend \"https://1.1.1.1/.well-known/dns-query\"" error="failed to perform an HTTPS request: Post https://1.1.1.1/.well-known/dns-query: EOF"

Any ideas on getting cloudflared to behave itself?

This looks similar to Cloudflared 1.1.1.1 - SSL issue


#2

Are you able to connect to 1.1.1.1 over https?

Can you curl as described in the link below successfully?

curl -v ‘https://1.1.1.1/dns-query?ct=application/dns-json&name=cloudflare.com’


#3

Thank you for your reply. I’ll update with a suitable response the next time it starts misbehaving.


#4

Hi, it happened again. cloudflared maxed out the CPU, so I curl'd as you suggested. Heres what I see:

$ curl -v 'https://1.1.1.1/dns-query?ct=application/dns-json&name=cloudflare.com'
*   Trying 1.1.1.1...
* TCP_NODELAY set
* Connected to 1.1.1.1 (1.1.1.1) port 443 (#0)
* ALPN, offering h2
* ALPN, offering http/1.1
* Cipher selection: ALL:!EXPORT:!EXPORT40:!EXPORT56:!aNULL:!LOW:!RC4:@STRENGTH
* successfully set certificate verify locations:
*   CAfile: /etc/ssl/certs/ca-certificates.crt
  CApath: /etc/ssl/certs
* TLSv1.2 (OUT), TLS header, Certificate Status (22):
* TLSv1.2 (OUT), TLS handshake, Client hello (1):
* TLSv1.2 (IN), TLS handshake, Server hello (2):
* TLSv1.2 (IN), TLS handshake, Certificate (11):
* TLSv1.2 (IN), TLS handshake, Server key exchange (12):
* TLSv1.2 (IN), TLS handshake, Server finished (14):
* TLSv1.2 (OUT), TLS handshake, Client key exchange (16):
* TLSv1.2 (OUT), TLS change cipher, Client hello (1):
* TLSv1.2 (OUT), TLS handshake, Finished (20):
* TLSv1.2 (IN), TLS change cipher, Client hello (1):
* TLSv1.2 (IN), TLS handshake, Finished (20):
* SSL connection using TLSv1.2 / ECDHE-ECDSA-AES128-GCM-SHA256
* ALPN, server accepted to use h2
* Server certificate:
*  subject: C=US; ST=CA; L=San Francisco; O=Cloudflare, Inc.; CN=*.cloudflare-dns.com
*  start date: Mar 30 00:00:00 2018 GMT
*  expire date: Mar 25 12:00:00 2020 GMT
*  subjectAltName: host "1.1.1.1" matched cert's IP address!
*  issuer: C=US; O=DigiCert Inc; CN=DigiCert ECC Secure Server CA
*  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
* Using Stream ID: 1 (easy handle 0x1162e48)
> GET /dns-query?ct=application/dns-json&name=cloudflare.com HTTP/1.1
> Host: 1.1.1.1
> User-Agent: curl/7.52.1
> Accept: */*
> 
* Connection state changed (MAX_CONCURRENT_STREAMS updated)!
< HTTP/2 200 
< date: Fri, 27 Apr 2018 14:44:08 GMT
< content-type: application/dns-json
< content-length: 289
< cache-control: max-age=578
< set-cookie: __cfduid=d25f2f1579425531eac7877479c666cba1524840248; expires=Sat, 27-Apr-19 14:44:08 GMT; path=/; domain=.1.1.1.1; HttpOnly; Secure
< server: cloudflare-nginx
< cf-ray: 412210beab6334dc-LHR
< 
* Curl_http_done: called premature == 0
* Connection #0 to host 1.1.1.1 left intact
{"Status": 0,"TC": false,"RD": true, "RA": true, "AD": true,"CD": false,"Question":[{"name": "cloudflare.com.", "type": 1}],"Answer":[{"name": "cloudflare.com.", "type": 1, "TTL": 578, "data": "198.41.214.162"},{"name": "cloudflare.com.", "type": 1, "TTL": 578, "data": "198.41.215.162"}]}[email protected]:~ $ 


 $ sudo systemctl status dnsproxy.service
● dnsproxy.service - CloudFlare DNS over HTTPS Proxy
   Loaded: loaded (/etc/systemd/system/dnsproxy.service; enabled; vendor preset: enabled)
   Active: active (running) since Wed 2018-04-25 09:00:02 UTC; 2 days ago
 Main PID: 5133 (cloudflared)
   CGroup: /system.slice/dnsproxy.service
           └─5133 /home/pi/argo-tunnel/cloudflared proxy-dns --port 54 --upstream https://1.1.1.1/.well-known/dns-query --upstream https://1.0.0.1/.well-known/dns-query

Apr 27 14:43:45 raspberrypi cloudflared[5133]: time="2018-04-27T14:43:45Z" level=error msg="failed to connect to an HTTPS backend \"https://1.1.1.1/.well-known/dns-query\"" error="failed to perform an HTTPS request: Post https://1.1.1.1/.well-known/dns-query: EOF"
Apr 27 14:43:52 raspberrypi cloudflared[5133]: time="2018-04-27T14:43:52Z" level=error msg="failed to connect to an HTTPS backend \"https://1.1.1.1/.well-known/dns-query\"" error="failed to perform an HTTPS request: Post https://1.1.1.1/.well-known/dns-query: EOF"
Apr 27 14:43:53 raspberrypi cloudflared[5133]: time="2018-04-27T14:43:53Z" level=error msg="failed to connect to an HTTPS backend \"https://1.1.1.1/.well-known/dns-query\"" error="failed to perform an HTTPS request: Post https://1.1.1.1/.well-known/dns-query: EOF"
Apr 27 14:43:56 raspberrypi cloudflared[5133]: time="2018-04-27T14:43:56Z" level=error msg="failed to connect to an HTTPS backend \"https://1.0.0.1/.well-known/dns-query\"" error="failed to perform an HTTPS request: Post https://1.0.0.1/.well-known/dns-query: EOF"
Apr 27 14:43:56 raspberrypi cloudflared[5133]: time="2018-04-27T14:43:56Z" level=error msg="failed to connect to an HTTPS backend \"https://1.1.1.1/.well-known/dns-query\"" error="failed to perform an HTTPS request: Post https://1.1.1.1/.well-known/dns-query: EOF"
Apr 27 14:43:59 raspberrypi cloudflared[5133]: time="2018-04-27T14:43:59Z" level=error msg="failed to connect to an HTTPS backend \"https://1.1.1.1/.well-known/dns-query\"" error="failed to perform an HTTPS request: Post https://1.1.1.1/.well-known/dns-query: EOF"
Apr 27 14:44:03 raspberrypi cloudflared[5133]: time="2018-04-27T14:44:03Z" level=error msg="failed to connect to an HTTPS backend \"https://1.1.1.1/.well-known/dns-query\"" error="failed to perform an HTTPS request: Post https://1.1.1.1/.well-known/dns-query: EOF"
Apr 27 14:44:09 raspberrypi cloudflared[5133]: time="2018-04-27T14:44:09Z" level=error msg="failed to connect to an HTTPS backend \"https://1.0.0.1/.well-known/dns-query\"" error="failed to perform an HTTPS request: Post https://1.0.0.1/.well-known/dns-query: EOF"
Apr 27 14:44:11 raspberrypi cloudflared[5133]: time="2018-04-27T14:44:11Z" level=error msg="failed to connect to an HTTPS backend \"https://1.0.0.1/.well-known/dns-query\"" error="failed to perform an HTTPS request: Post https://1.0.0.1/.well-known/dns-query: EOF"
Apr 27 14:44:18 raspberrypi cloudflared[5133]: time="2018-04-27T14:44:18Z" level=error msg="failed to connect to an HTTPS backend \"https://1.0.0.1/.well-known/dns-query\"" error="failed to perform an HTTPS request: Post https://1.0.0.1/.well-known/dns-query: EOF"
 $ 

#5

Thanks for the additional detail, I’ve filed a bug report to ask the dev team to take a look.


#6

The EOFs are connection closures between the proxy and Cloudflare’s edge. It can happen during route changes / service upgrades / other reasons. It shouldn’t max the CPU though. Do you run a dnsmasq or something else in front of cloudflared (since you’re binding to port 54)? Can you check logs (or metrics) there to make sure cloudflared not being flooded with queries?


#7

Hi, yes, I’m running dnsmasq detailed below:

● dnsmasq.service - dnsmasq - A lightweight DHCP and caching DNS server
   Loaded: loaded (/lib/systemd/system/dnsmasq.service; enabled; vendor preset: enabled)
   Active: active (running) since Sun 2018-04-29 20:19:06 UTC; 39min ago
  Process: 1047 ExecStop=/etc/init.d/dnsmasq systemd-stop-resolvconf (code=exited, status=0/SUCCESS)
  Process: 1105 ExecStartPost=/etc/init.d/dnsmasq systemd-start-resolvconf (code=exited, status=0/SUCCESS)
  Process: 1098 ExecStart=/etc/init.d/dnsmasq systemd-exec (code=exited, status=0/SUCCESS)
  Process: 1095 ExecStartPre=/usr/sbin/dnsmasq --test (code=exited, status=0/SUCCESS)
 Main PID: 1104 (dnsmasq)
   CGroup: /system.slice/dnsmasq.service
           └─1104 /usr/sbin/dnsmasq -x /run/dnsmasq/dnsmasq.pid -u dnsmasq -r /run/dnsmasq/resolv.conf -7 /etc/dnsmasq.d,.dpkg-dist,.dpkg-old,.dpkg-new --local-service

Apr 29 20:19:04 raspberrypi systemd[1]: Starting dnsmasq - A lightweight DHCP and caching DNS server...
Apr 29 20:19:04 raspberrypi dnsmasq[1095]: dnsmasq: syntax check OK.
Apr 29 20:19:06 raspberrypi systemd[1]: Started dnsmasq - A lightweight DHCP and caching DNS server.

There’s nothing unusual in the logs. An example:

Apr 29 21:02:43 dnsmasq[1104]: 6097 127.0.0.1/39715 query[A] 1.debian.pool.ntp.org from 127.0.0.1
Apr 29 21:02:43 dnsmasq[1104]: 6097 127.0.0.1/39715 forwarded 1.debian.pool.ntp.org to 127.0.0.1
Apr 29 21:02:43 dnsmasq[1104]: 6098 127.0.0.1/39715 query[AAAA] 1.debian.pool.ntp.org from 127.0.0.1
Apr 29 21:02:43 dnsmasq[1104]: 6098 127.0.0.1/39715 forwarded 1.debian.pool.ntp.org to 127.0.0.1

I notice that the curl output given previously works fine, but curl -v "https://1.1.1.1/.well-known/dns-query" ... is resulting in a 500 error:

$ curl -v "https://1.1.1.1/.well-known/dns-query" -X POST -H "Content-Type: application/dns-json" -d '{"name":"cloudflare.com"}'
Note: Unnecessary use of -X or --request, POST is already inferred.
*   Trying 1.1.1.1...
* TCP_NODELAY set
* Connected to 1.1.1.1 (1.1.1.1) port 443 (#0)
* ALPN, offering h2
* ALPN, offering http/1.1
* Cipher selection: ALL:!EXPORT:!EXPORT40:!EXPORT56:!aNULL:!LOW:!RC4:@STRENGTH
* successfully set certificate verify locations:
*   CAfile: /etc/ssl/certs/ca-certificates.crt
  CApath: /etc/ssl/certs
* TLSv1.2 (OUT), TLS header, Certificate Status (22):
* TLSv1.2 (OUT), TLS handshake, Client hello (1):
* TLSv1.2 (IN), TLS handshake, Server hello (2):
* TLSv1.2 (IN), TLS handshake, Certificate (11):
* TLSv1.2 (IN), TLS handshake, Server key exchange (12):
* TLSv1.2 (IN), TLS handshake, Server finished (14):
* TLSv1.2 (OUT), TLS handshake, Client key exchange (16):
* TLSv1.2 (OUT), TLS change cipher, Client hello (1):
* TLSv1.2 (OUT), TLS handshake, Finished (20):
* TLSv1.2 (IN), TLS change cipher, Client hello (1):
* TLSv1.2 (IN), TLS handshake, Finished (20):
* SSL connection using TLSv1.2 / ECDHE-ECDSA-AES128-GCM-SHA256
* ALPN, server accepted to use h2
* Server certificate:
*  subject: C=US; ST=CA; L=San Francisco; O=Cloudflare, Inc.; CN=*.cloudflare-dns.com
*  start date: Mar 30 00:00:00 2018 GMT
*  expire date: Mar 25 12:00:00 2020 GMT
*  subjectAltName: host "1.1.1.1" matched cert's IP address!
*  issuer: C=US; O=DigiCert Inc; CN=DigiCert ECC Secure Server CA
*  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
* Using Stream ID: 1 (easy handle 0x1a17e48)
> POST /.well-known/dns-query HTTP/1.1
> Host: 1.1.1.1
> User-Agent: curl/7.52.1
> Accept: */*
> Content-Type: application/dns-json
> Content-Length: 25
> 
* Connection state changed (MAX_CONCURRENT_STREAMS updated)!
* We are completely uploaded and fine
< HTTP/2 500 
< date: Sun, 29 Apr 2018 21:27:11 GMT
< set-cookie: __cfduid=db5e608b1fc6ab4050aa9ab4ed6ddeb131525037231; expires=Mon, 29-Apr-19 21:27:11 GMT; path=/; domain=.1.1.1.1; HttpOnly; Secure
< server: cloudflare-nginx
< cf-ray: 4134d9e6af9034d6-LHR
< 
* Curl_http_done: called premature == 0
* Connection #0 to host 1.1.1.1 left intact

Maybe I’ve got the content type and/or the POST body wrong though :frowning:


#8

Hi!

I’m having exactly the same problem (I also followed Scott blog post) and I’ve even tried the latest cloudflared version (cloudflared version 2018.5.3 (built 2018-05-11-1704 UTC)) but I can’t solve the problem, I always get this error:

[email protected]:/var/log $ sudo systemctl status dnsproxy.service

● dnsproxy.service - CloudFlare DNS over HTTPS Proxy
Loaded: loaded (/etc/systemd/system/dnsproxy.service; enabled; vendor preset: enabled)
Active: active (running) since Sat 2018-05-12 09:48:54 UTC; 14min ago
Main PID: 25187 (cloudflared)
CGroup: /system.slice/dnsproxy.service
└─25187 /home/pi/argo-tunnel/cloudflared proxy-dns --port 54

May 12 10:03:16 raspberrypi cloudflared[25187]: time=“2018-05-12T10:03:16Z” level=error msg=“failed to connect to an HTTPS backend “https://1.0.0.1/dns-query”” error="failed to perform an HTTPS request: Post https://1.0.0.1/dns-query: net/http: request canceled while wa

have you been able to fix it in the mean time? I had to give up and disable it :confused: