`cloudflared tunnel run` silently fails

[Changaco]

In the last two days, cloudflared has silently failed 3 times, for no apparent reason. Each time, trying to access the website in a browser showed a blank page (no error message, nothing), so it looks like cloudflared was sending valid but empty responses back to the edge instead of forwarding the requests to the webapp. Each time, restarting cloudflared restored access to the website, so it seems clear that the problem is in cloudflared and not in the webapp. Updating cloudflared from 2021.6.0 to 2021.11.0 hasn't fixed the problem.

The connections to the edge are HTTP2, and the requests are passed to the webapp through a Unix socket. You can see the cloudflared service and configuration files in https://github.com/liberapay/liberapay.com/tree/635/.platform/files.

Considering the precedent of #400, I'm thinking about writing my own tunnel implementation so that I can stop using cloudflared entirely.

[nmldiegues]

I'm afraid this is the first time we hear about such issue, so we won't have a magic bullet to help solve it.

Can you run cloudflared with loglevel: debug and provide us with the logs when this happens next time?

I'm thinking about writing my own tunnel implementation so that I can stop using cloudflared entirely.

If you are happy to develop, I'd argue that this will be far more work than if, instead, you try to debug what's happening in cloudflared when it happens (it is an open source project after all) and contribute with the fix.

[Changaco]

I've changed the logging level to debug, but there's no guarantee that the failure will happen again.

I'm not familiar with the Go language and its ecosystem, so I don't really understand the source code of cloudflared.

[Changaco]

The breakdown happened during the night again. That's 3 nights in a row. The cloudflared debug log abruptly stopped after the normal processing of request 6b4786ef09d53ff5-CDG. Presumably the cloudflared process was still alive, otherwise systemd should have restarted it. This might mean that the edge stopped forwarding requests to cloudflared completely.

This time I remembered to dump a response before restarting cloudflared, so we now have a bit more data:

$ curl -v 'https://liberapay.com/'
*   Trying 104.21.69.181:443...
* Connected to liberapay.com (104.21.69.181) port 443 (#0)
* ALPN, offering h2
* ALPN, offering http/1.1
*  CAfile: /etc/ssl/certs/ca-certificates.crt
*  CApath: none
* TLSv1.3 (OUT), TLS handshake, Client hello (1):
* TLSv1.3 (IN), TLS handshake, Server hello (2):
* TLSv1.3 (IN), TLS handshake, Encrypted Extensions (8):
* TLSv1.3 (IN), TLS handshake, Certificate (11):
* TLSv1.3 (IN), TLS handshake, CERT verify (15):
* TLSv1.3 (IN), TLS handshake, Finished (20):
* TLSv1.3 (OUT), TLS change cipher, Change cipher spec (1):
* TLSv1.3 (OUT), TLS handshake, Finished (20):
* SSL connection using TLSv1.3 / TLS_AES_256_GCM_SHA384
* ALPN, server accepted to use h2
* Server certificate:
*  subject: C=US; ST=California; L=San Francisco; O=Cloudflare, Inc.; CN=sni.cloudflaressl.com
*  start date: Jul  3 00:00:00 2021 GMT
*  expire date: Jul  2 23:59:59 2022 GMT
*  subjectAltName: host "liberapay.com" matched cert's "liberapay.com"
*  issuer: C=US; O=Cloudflare, Inc.; CN=Cloudflare Inc ECC CA-3
*  SSL certificate verify ok.
* Using HTTP2, server supports multiplexing
* 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 0x564d417d19d0)
> GET / HTTP/2
> Host: liberapay.com
> user-agent: curl/7.80.0
> accept: */*
> 
* TLSv1.3 (IN), TLS handshake, Newsession Ticket (4):
* TLSv1.3 (IN), TLS handshake, Newsession Ticket (4):
* old SSL session ID is stale, removing
* Connection state changed (MAX_CONCURRENT_STREAMS == 256)!
< HTTP/2 503 
< date: Sat, 27 Nov 2021 06:36:39 GMT
< content-type: text/plain; charset=utf-8
< content-length: 1
< x-content-type-options: nosniff
< cf-cache-status: DYNAMIC
< expect-ct: max-age=604800, report-uri="https://report-uri.cloudflare.com/cdn-cgi/beacon/expect-ct"
< report-to: {"endpoints":[{"url":"https:\/\/a.nel.cloudflare.com\/report\/v3?s=dSB4llvs7R54irEeR1dWubGJSo%2FPIsIsgB6gEiO635%2FB055d%2Big%2BgUx%2B5fPGgujN22WGHSQvegTRM1k364UPMHioVPZ5miUL3RuTDdBS7HEx5pixmmj0KxS9O9vclo5I"}],"group":"cf-nel","max_age":604800}
< nel: {"success_fraction":0,"report_to":"cf-nel","max_age":604800}
< strict-transport-security: max-age=31536000; includeSubDomains; preload
< server: cloudflare
< cf-ray: 6b4957e57a8a39c9-CDG
< alt-svc: h3=":443"; ma=86400, h3-29=":443"; ma=86400, h3-28=":443"; ma=86400, h3-27=":443"; ma=86400
< 

* Connection #0 to host liberapay.com left intact

[gvccvwangmingn2]

@Changaco had a similar issue but using quic protocol. requests are not coming through unless exit signal is given and client gets 5xx instead. it was fixed #473

can you try running cloudflared on screen session instead of systemd? when request fails, try executing CTRL+C/exit signal on the cloudflared screen session, and print the output here.

[nmldiegues]

We have identified a situation similar to the one described here, where cloudflared with QUIC transport could become seemingly stuck, and fixed it in 2022.2.0 with ed2bac0

So to the best of our belief, this one should be addressed.