Unreliable reverse proxying to NGINX upstream. Periodic 502 Bad Gateway from Caddy

1. Caddy version (caddy version):

v2.2.1 h1:Q62GWHMtztnvyRU+KPOpw6fNfeCD3SkwH7SfT1Tgt2c=

2. How I run Caddy:

/usr/bin/caddy run --environ --config /etc/caddy/Caddyfile

I run caddy as a reverse proxy for Jellyfin and a web app.

a. System environment:

Ubunut Server 20.04

b. Command:

/usr/bin/caddy run --environ --config /etc/caddy/Caddyfile

c. Service/unit/compose file:

N/A

d. My complete Caddyfile or JSON config:

{
        debug
}

media.moochermedia.co {
        reverse_proxy 192.168.2.32:8096
}

projectaeon.clawfoot.dev {
        reverse_proxy :443 10.10.10.10:443 {
                transport http {
                        tls
                        tls_insecure_skip_verify
                        compression off
                }
                header_up Host {http.request.host}
                header_up X-Real-IP {http.request.remote}
                header_up X-Forwarded-For {http.request.remote}
                header_up X-Forwarded-Port {http.request.port}
                header_up X-Forwarded-Proto {http.request.scheme}
        }
}

3. The problem I’m having:

The projectaeon.clawfoot.dev is getting intermittent 502 errors. This is forwarding to an NGINX upstream. If I remove caddy from the mix, the site that NGINX is serving up serves up perfectly.

Please note that this is intermittent, it’s not constant. Sometimes I’ll get a 200 OK, most of the time I’ll get 502.

4. Error messages and/or full log output:

Caddy Log

admin@Caddy-Proxy:~$ /usr/bin/caddy run --environ --config /etc/caddy/Caddyfile
caddy.HomeDir=/home/admin
caddy.AppDataDir=/home/admin/.local/share/caddy
caddy.AppConfigDir=/home/admin/.config/caddy
caddy.ConfigAutosavePath=/home/admin/.config/caddy/autosave.json
caddy.Version=v2.2.1
runtime.GOOS=linux
runtime.GOARCH=amd64
runtime.Compiler=gc
runtime.NumCPU=2
runtime.GOMAXPROCS=2
runtime.Version=go1.15.2
os.Getwd=/home/admin

SHELL=/bin/bash
PWD=/home/admin
LOGNAME=admin
XDG_SESSION_TYPE=tty
MOTD_SHOWN=pam
HOME=/home/admin
LANG=en_US.UTF-8
LS_COLORS=rs=0:di=01;34:ln=01;36:mh=00:pi=40;33:so=01;35:do=01;35:bd=40;33;01:cd=40;33;01:or=40;31;01:mi=00:su=37;41:sg=30;43:ca=30;41:tw=30;42:ow=34;42:st=37;44:ex=01;32:*.tar=01;31:*.tgz=01;31:*.arc=01;31:*.arj=01;31:*.taz=01;31:*.lha=01;31:*.lz4=01;31:*.lzh=01;31:*.lzma=01;31:*.tlz=01;31:*.txz=01;31:*.tzo=01;31:*.t7z=01;31:*.zip=01;31:*.z=01;31:*.dz=01;31:*.gz=01;31:*.lrz=01;31:*.lz=01;31:*.lzo=01;31:*.xz=01;31:*.zst=01;31:*.tzst=01;31:*.bz2=01;31:*.bz=01;31:*.tbz=01;31:*.tbz2=01;31:*.tz=01;31:*.deb=01;31:*.rpm=01;31:*.jar=01;31:*.war=01;31:*.ear=01;31:*.sar=01;31:*.rar=01;31:*.alz=01;31:*.ace=01;31:*.zoo=01;31:*.cpio=01;31:*.7z=01;31:*.rz=01;31:*.cab=01;31:*.wim=01;31:*.swm=01;31:*.dwm=01;31:*.esd=01;31:*.jpg=01;35:*.jpeg=01;35:*.mjpg=01;35:*.mjpeg=01;35:*.gif=01;35:*.bmp=01;35:*.pbm=01;35:*.pgm=01;35:*.ppm=01;35:*.tga=01;35:*.xbm=01;35:*.xpm=01;35:*.tif=01;35:*.tiff=01;35:*.png=01;35:*.svg=01;35:*.svgz=01;35:*.mng=01;35:*.pcx=01;35:*.mov=01;35:*.mpg=01;35:*.mpeg=01;35:*.m2v=01;35:*.mkv=01;35:*.webm=01;35:*.ogm=01;35:*.mp4=01;35:*.m4v=01;35:*.mp4v=01;35:*.vob=01;35:*.qt=01;35:*.nuv=01;35:*.wmv=01;35:*.asf=01;35:*.rm=01;35:*.rmvb=01;35:*.flc=01;35:*.avi=01;35:*.fli=01;35:*.flv=01;35:*.gl=01;35:*.dl=01;35:*.xcf=01;35:*.xwd=01;35:*.yuv=01;35:*.cgm=01;35:*.emf=01;35:*.ogv=01;35:*.ogx=01;35:*.aac=00;36:*.au=00;36:*.flac=00;36:*.m4a=00;36:*.mid=00;36:*.midi=00;36:*.mka=00;36:*.mp3=00;36:*.mpc=00;36:*.ogg=00;36:*.ra=00;36:*.wav=00;36:*.oga=00;36:*.opus=00;36:*.spx=00;36:*.xspf=00;36:
SSH_CONNECTION=192.168.2.10 63676 192.168.2.2 22
LESSCLOSE=/usr/bin/lesspipe %s %s
XDG_SESSION_CLASS=user
TERM=xterm
LESSOPEN=| /usr/bin/lesspipe %s
USER=admin
SHLVL=1
XDG_SESSION_ID=60
XDG_RUNTIME_DIR=/run/user/1001
SSH_CLIENT=192.168.2.10 63676 22
XDG_DATA_DIRS=/usr/local/share:/usr/share:/var/lib/snapd/desktop
PATH=/usr/local/sbin:/usr/local/bin:/usr/sbin:/usr/bin:/sbin:/bin:/usr/games:/usr/local/games:/snap/bin
DBUS_SESSION_BUS_ADDRESS=unix:path=/run/user/1001/bus
SSH_TTY=/dev/pts/0
_=/usr/bin/caddy
2020/12/29 22:15:50.265 INFO    using provided configuration    {"config_file": "/etc/caddy/Caddyfile", "config_adapter": ""}
2020/12/29 22:15:50.267 INFO    admin   admin endpoint started  {"address": "tcp/localhost:2019", "enforce_origin": false, "origins": ["127.0.0.1:2019", "localhost:2019", "[::1]:2019"]}
2020/12/29 22:15:50.268 INFO    tls.cache.maintenance   started background certificate maintenance      {"cache": "0xc0002f1f80"}
2020/12/29 22:15:50.268 INFO    http    server is listening only on the HTTPS port but has no TLS connection policies; adding one to enable TLS {"server_name": "srv0", "https_port": 443}
2020/12/29 22:15:50.268 INFO    http    enabling automatic HTTP->HTTPS redirects        {"server_name": "srv0"}
2020/12/29 22:15:50.269 DEBUG   http    starting server loop    {"address": "[::]:80", "http3": false, "tls": false}
2020/12/29 22:15:50.269 DEBUG   http    starting server loop    {"address": "[::]:443", "http3": false, "tls": true}
2020/12/29 22:15:50.269 INFO    http    enabling automatic TLS certificate management   {"domains": ["projectaeon.clawfootsoftware.com", "projectaeon.clawfoot.dev", "media.moochermedia.co"]}
2020/12/29 22:15:50.271 INFO    tls     cleaned up storage units
2020/12/29 22:15:50.283 INFO    autosaved config        {"file": "/home/admin/.config/caddy/autosave.json"}
2020/12/29 22:15:50.283 INFO    serving initial configuration
2020/12/29 22:15:52.706 DEBUG   http.stdlib     http: TLS handshake error from 127.0.0.1:45836: no certificate available for '127.0.0.1'
2020/12/29 22:15:52.706 DEBUG   http.handlers.reverse_proxy     upstream roundtrip      {"upstream": ":443", "request": {"remote_addr": "192.168.2.1:60937", "proto": "HTTP/2.0", "method": "GET", "host": "projectaeon.clawfoot.dev", "uri": "/dist/semantic.min.js", "headers": {"Dnt": ["1"], "X-Real-Ip": ["192.168.2.1:60937"], "X-Forwarded-Port": [""], "User-Agent": ["Mozilla/5.0 (Windows NT 10.0; Win64; x64; rv:84.0) Gecko/20100101 Firefox/84.0"], "X-Forwarded-For": ["192.168.2.1:60937"], "Sec-Gpc": ["1"], "Accept": ["text/html,application/xhtml+xml,application/xml;q=0.9,image/webp,*/*;q=0.8"], "Upgrade-Insecure-Requests": ["1"], "Te": ["trailers"], "Accept-Language": ["en-US,en;q=0.5"], "Pragma": ["no-cache"], "Cache-Control": ["no-cache"], "X-Forwarded-Proto": ["https"], "Accept-Encoding": ["gzip, deflate, br"]}, "tls": {"resumed": false, "version": 772, "cipher_suite": 4865, "proto": "h2", "proto_mutual": true, "server_name": "projectaeon.clawfoot.dev"}}, "duration": 0.000896393, "error": "remote error: tls: internal error"}
2020/12/29 22:15:52.707 ERROR   http.log.error  remote error: tls: internal error       {"request": {"remote_addr": "192.168.2.1:60937", "proto": "HTTP/2.0", "method": "GET", "host": "projectaeon.clawfoot.dev", "uri": "/dist/semantic.min.js", "headers": {"Upgrade-Insecure-Requests": ["1"], "Dnt": ["1"], "Sec-Gpc": ["1"], "Pragma": ["no-cache"], "Te": ["trailers"], "User-Agent": ["Mozilla/5.0 (Windows NT 10.0; Win64; x64; rv:84.0) Gecko/20100101 Firefox/84.0"], "Accept": ["text/html,application/xhtml+xml,application/xml;q=0.9,image/webp,*/*;q=0.8"], "Accept-Language": ["en-US,en;q=0.5"], "Accept-Encoding": ["gzip, deflate, br"], "Cache-Control": ["no-cache"]}, "tls": {"resumed": false, "version": 772, "cipher_suite": 4865, "proto": "h2", "proto_mutual": true, "server_name": "projectaeon.clawfoot.dev"}}, "duration": 0.001462174, "status": 502, "err_id": "dkre7jr7a", "err_trace": "reverseproxy.(*Handler).ServeHTTP (reverseproxy.go:441)"}
2020/12/29 22:15:52.789 DEBUG   http.handlers.reverse_proxy     upstream roundtrip      {"upstream": "10.10.10.10:443", "request": {"remote_addr": "192.168.2.1:60937", "proto": "HTTP/2.0", "method": "GET", "host": "projectaeon.clawfoot.dev", "uri": "/favicon.ico", "headers": {"Te": ["trailers"], "X-Forwarded-For": ["192.168.2.1:60937"], "Accept-Encoding": ["gzip, deflate, br"], "Cache-Control": ["no-cache"], "Dnt": ["1"], "Sec-Gpc": ["1"], "Pragma": ["no-cache"], "Accept": ["image/webp,*/*"], "X-Real-Ip": ["192.168.2.1:60937"], "Referer": ["https://projectaeon.clawfoot.dev/dist/semantic.min.js"], "Accept-Language": ["en-US,en;q=0.5"], "X-Forwarded-Port": [""], "User-Agent": ["Mozilla/5.0 (Windows NT 10.0; Win64; x64; rv:84.0) Gecko/20100101 Firefox/84.0"], "X-Forwarded-Proto": ["https"]}, "tls": {"resumed": false, "version": 772, "cipher_suite": 4865, "proto": "h2", "proto_mutual": true, "server_name": "projectaeon.clawfoot.dev"}}, "duration": 0.010050231, "headers": {"Server": ["nginx/1.18.0 (Ubuntu)"], "Date": ["Tue, 29 Dec 2020 22:15:52 GMT"], "Content-Length": ["0"], "Connection": ["keep-alive"]}, "status": 404}
2020/12/29 22:15:57.209 DEBUG   http.stdlib     http: TLS handshake error from 127.0.0.1:45840: no certificate available for '127.0.0.1'
2020/12/29 22:15:57.209 DEBUG   http.handlers.reverse_proxy     upstream roundtrip      {"upstream": ":443", "request": {"remote_addr": "192.168.2.1:21478", "proto": "HTTP/2.0", "method": "GET", "host": "projectaeon.clawfoot.dev", "uri": "/dist/semantic.min.js", "headers": {"Upgrade-Insecure-Requests": ["1"], "X-Forwarded-Port": [""], "Pragma": ["no-cache"], "Accept-Encoding": ["gzip, deflate, br"], "X-Real-Ip": ["192.168.2.1:21478"], "Dnt": ["1"], "Cache-Control": ["no-cache"], "Te": ["trailers"], "X-Forwarded-Proto": ["https"], "Sec-Gpc": ["1"], "Accept-Language": ["en-US,en;q=0.5"], "X-Forwarded-For": ["192.168.2.1:21478"], "User-Agent": ["Mozilla/5.0 (Windows NT 10.0; Win64; x64; rv:84.0) Gecko/20100101 Firefox/84.0"], "Accept": ["text/html,application/xhtml+xml,application/xml;q=0.9,image/webp,*/*;q=0.8"]}, "tls": {"resumed": true, "version": 772, "cipher_suite": 4865, "proto": "h2", "proto_mutual": true, "server_name": "projectaeon.clawfoot.dev"}}, "duration": 0.00068301, "error": "remote error: tls: internal error"}
2020/12/29 22:15:57.209 ERROR   http.log.error  remote error: tls: internal error       {"request": {"remote_addr": "192.168.2.1:21478", "proto": "HTTP/2.0", "method": "GET", "host": "projectaeon.clawfoot.dev", "uri": "/dist/semantic.min.js", "headers": {"Accept": ["text/html,application/xhtml+xml,application/xml;q=0.9,image/webp,*/*;q=0.8"], "Accept-Language": ["en-US,en;q=0.5"], "Upgrade-Insecure-Requests": ["1"], "Dnt": ["1"], "Pragma": ["no-cache"], "Cache-Control": ["no-cache"], "User-Agent": ["Mozilla/5.0 (Windows NT 10.0; Win64; x64; rv:84.0) Gecko/20100101 Firefox/84.0"], "Sec-Gpc": ["1"], "Te": ["trailers"], "Accept-Encoding": ["gzip, deflate, br"]}, "tls": {"resumed": true, "version": 772, "cipher_suite": 4865, "proto": "h2", "proto_mutual": true, "server_name": "projectaeon.clawfoot.dev"}}, "duration": 0.000871838, "status": 502, "err_id": "5fmc9b808", "err_trace": "reverseproxy.(*Handler).ServeHTTP (reverseproxy.go:441)"}
2020/12/29 22:15:57.324 DEBUG   http.handlers.reverse_proxy     upstream roundtrip      {"upstream": "10.10.10.10:443", "request": {"remote_addr": "192.168.2.1:21478", "proto": "HTTP/2.0", "method": "GET", "host": "projectaeon.clawfoot.dev", "uri": "/favicon.ico", "headers": {"Dnt": ["1"], "Sec-Gpc": ["1"], "X-Forwarded-Port": [""], "Accept": ["image/webp,*/*"], "Referer": ["https://projectaeon.clawfoot.dev/dist/semantic.min.js"], "Te": ["trailers"], "Cache-Control": ["no-cache"], "X-Forwarded-For": ["192.168.2.1:21478"], "Pragma": ["no-cache"], "X-Real-Ip": ["192.168.2.1:21478"], "User-Agent": ["Mozilla/5.0 (Windows NT 10.0; Win64; x64; rv:84.0) Gecko/20100101 Firefox/84.0"], "X-Forwarded-Proto": ["https"], "Accept-Language": ["en-US,en;q=0.5"], "Accept-Encoding": ["gzip, deflate, br"]}, "tls": {"resumed": true, "version": 772, "cipher_suite": 4865, "proto": "h2", "proto_mutual": true, "server_name": "projectaeon.clawfoot.dev"}}, "duration": 0.003401106, "headers": {"Server": ["nginx/1.18.0 (Ubuntu)"], "Date": ["Tue, 29 Dec 2020 22:15:57 GMT"], "Content-Length": ["0"], "Connection": ["keep-alive"]}, "status": 404}
^C2020/12/29 22:16:09.334       INFO    shutting down   {"signal": "SIGINT"}
2020/12/29 22:16:10.335 INFO    tls.cache.maintenance   stopped background certificate maintenance      {"cache": "0xc0002f1f80"}
2020/12/29 22:16:10.836 INFO    admin   stopped previous server
2020/12/29 22:16:10.836 INFO    shutdown done   {"signal": "SIGINT"}

NGINX Config
user admin;
worker_processes auto;
pid /run/nginx.pid;
include /etc/nginx/modules-enabled/*.conf;

events {
	worker_connections 768;
	# multi_accept on;
}

http {
    log_format  main  '$remote_addr - $remote_user [$time_local] "$request" '
                      '$status $body_bytes_sent "$http_referer" '
                      '"$http_user_agent" "$http_x_forwarded_for"';

    access_log  /var/log/nginx/access.log  main;
    error_log /var/log/nginx/error.log debug;

    sendfile            on;
    tcp_nopush          on;
    tcp_nodelay         on;
    keepalive_timeout   65;
    types_hash_max_size 2048;

    include             /etc/nginx/mime.types;
    default_type        application/octet-stream;

    # Load modular configuration files from the /etc/nginx/conf.d directory.
    # See http://nginx.org/en/docs/ngx_core_module.html#include
    # for more information.
    include /etc/nginx/conf.d/*.conf;

    server {
	listen 80 default_server;
	server_name _;

	return 301 https://$host$request_uri;
    }

    server {
        listen        443 ssl;
	ssl_certificate	/etc/ssl/certs/nginx-selfsigned.crt;
	ssl_certificate_key /etc/ssl/private/nginx-selfsigned.key;

	ssl_session_cache 	builtin:1000 shared:SSL:10m;
	ssl_protocols	TLSv1 TLSv1.1 TLSv1.2 TLSv1.3;
	ssl_prefer_server_ciphers on;
    
        gzip_vary on;
        gzip_types
                 text/css
                 text/javascript
                 text/xml
                 text/plain
                 text/x-component
                 application/javascript
                 application/json
                 application/xml
                 application/rss+xml
                 font/truetype
                 font/opentype
                 application/vnd.ms-fontobject
                 image/svg+xml;

        server_name   _;
	location /dist/ {
		autoindex off;
		alias /home/admin/[redacted]/wwwroot/dist/;
	}
        location /css/ {
                autoindex off;
                alias /home/admin/[redacted]/wwwroot/css/;
        }
        location /img/ {
                autoindex off;
                alias /home/admin/[redacted]/wwwroot/img/;
        }
        location /js/ {
                autoindex off;
                alias /home/admin/[redacted]/wwwroot/js/;
        }
        location /api/player/hub {
                proxy_pass http://localhost:5000;
                proxy_http_version 1.1;
                proxy_set_header Upgrade $http_upgrade;
                proxy_set_header Connection "upgrade";
                proxy_set_header Host $host;
                proxy_cache_bypass $http_upgrade;
        }
        location / {
                proxy_pass         http://localhost:5000;
                proxy_http_version 1.1;
                proxy_set_header   Upgrade $http_upgrade;
                proxy_set_header   Connection keep-alive;
                proxy_set_header   Host $host;
                proxy_cache_bypass $http_upgrade;
                proxy_set_header   X-Forwarded-For $proxy_add_x_forwarded_for;
                proxy_set_header   X-Forwarded-Proto $scheme;
        }
    }
}
NGINX Debug Log

2020/12/29 22:15:10 [debug] 2075#2075: epoll add event: fd:6 op:1 ev:100000012 - Pastebin.com

Even if I change Caddy to proxy to port 80 (And configure NGINX to only listen on port 80) The intermittent issues still occure (But instead of a 502, come back as Client sent an HTTP request to an HTTPS server.) However this error coincides with teh following lines:

Note: This occures probably 1/2 the time, it’s inconsistent.

2020/12/29 22:40:52.907 ERROR   http.handlers.reverse_proxy     reading from backend    {"error": "read tcp 127.0.0.1:45904->127.0.0.1:443: read: connection reset by peer"}
2020/12/29 22:40:52.907 ERROR   http.handlers.reverse_proxy     aborting with incomplete response       {"error": "read tcp 127.0.0.1:45904->127.0.0.1:443: read: connection reset by peer"}

5. What I already tried:

I’m not sure how to answer this. I’ve been trying to sort this out for actual days, the answer here would be “Everything I can find, and nothing has helped make progress”. Unfortunately I cannot find the info I need to actually make any progress here. Narrow google searches have 1-2 or zero results.

compression off is an artifact of this. Same with the headers.

This seems to be related to: 502 error when proxy to caddy https upstream - #3 by renothing ?

6. Links to relevant resources:

So… I just removed the :443 binding from reverse_proxy :443 10.10.10.10:443 so it’s now reverse_proxy 10.10.10.10:443 and no more issues.

So my questions are:

  • Why was this failing?
  • Why was it failing intermittently instead of constantly?

It’s because you have an extra :443 in there.

Caddy is making requests to 127.0.0.1:443 for half of the requests, because by default Caddy will use a round robin load balancing policy when configured with more than one backend. So every second request will fail.

Basically, you’re telling Caddy to proxy to itself half the time.

Just remove the extra :443 and it should work fine.

Also, all those header_up lines are not necessary. You should remove them. See the proxy docs:

1 Like

Hi @francislavoie thanks for the reply!
To clarify my understanding. I was using :443 as a only proxy from :443. Instead that was actually telling Caddy that there is a 2nd upstream at :443which comes out as127.0.0.1:443`?

If so, I had a fundamental misunderstanding of how to only care about :443 traffic. I knew this was going to be some fundamental, small, config issue :expressionless:

Also, as for it failing every other request. I ran 100 requests like this, and 78 of them failed. Sometimes I would get a string of 2-3 successes, but most of the time it would be 4-5 failures in a row delineated with a single success. Not arguing anything there, just pointing out that it was somewhat different than the statement.

Again, thanks!

That’s right.

Yeah, you’re using incorrect syntax. See the request matcher docs:

But even then, it’s not necessary to try to limit it to :443, because that’s implicit. Caddy will redirect HTTP requests to HTTPS for any configured site (unless explicitly disabled or overriden by a :80 block), so only HTTPS requests will make it to your projectaeon.clawfoot.dev site block.

Are you doing that test with a browser? The browser will make more requests when it tries to load some JS/CSS files or even the favicon.ico, so it might not appear to be every 2nd that fails because of the order in which the requests end up hitting Caddy.

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