context canceled and 502 #1925

rafales · 2017-10-17T21:12:25Z

1. What version of Caddy are you using (`caddy -version`)?

0.10.10

2. What are you trying to do?

Proxy an express app.

Seems like caddy responds with 502 and complains when I write the request and close the socket for writing. I'm still available for reading, so caddy should send me the proper response.

Note that request gets proxied just fine (I can see in webapp's logs). If I enter request in nc manually without closing the stdin then I get the right response.

3. What is your entire Caddyfile?

localhost:80
tls off
log stdout
errors stderr
proxy /media imageserver
proxy /api server:3200 {
    keepalive 0
}

4. How did you run Caddy (give the full command and describe the execution environment)?

Docker, abiosoft/caddy image.

5. Please paste any relevant HTTP request(s) here.

➜  ~  cat request.txt 
POST /api/graphql HTTP/1.1
Host: localhost:3200
Content-Length: 132
Content-type: application/json
Authorization: Bearer R+VNcynE/pbt5lVgLVGlFVhxQpj5DOjs4dNPWqeGHFGPz41XdD7RFQjbrYDoPesA

{"operationName":"currentUser","variables":{},"query":"query currentUser {\n  viewer {\n    id\n    name\n    __typename\n  }\n}\n"}

➜  ~  nc localhost 3200 < request.txt
HTTP/1.1 502 Bad Gateway
Content-Type: text/plain; charset=utf-8
Server: Caddy
X-Content-Type-Options: nosniff
Date: Tue, 17 Oct 2017 21:06:29 GMT
Content-Length: 16

502 Bad Gateway

6. What did you expect to see?

A proper JSON response.

7. What did you see instead (give full error messages and/or log)?

gateway_1     | 172.18.0.1 - - [17/Oct/2017:21:04:30 +0000] "POST /api/graphql HTTP/1.1" 502 16
gateway_1     | 17/Oct/2017:21:04:30 +0000 [ERROR 502 /api/graphql] context canceled

The text was updated successfully, but these errors were encountered:

rafales · 2017-10-17T21:13:02Z

Btw this is reproducible every time.

ubergesundheit · 2017-10-21T10:17:11Z

I think this is related to #1828 and https://caddy.community/t/error-context-canceled/2034

The request goes through to the backend, but the user gets a 502 Bad Gateway error.

ionphractal · 2018-03-03T14:31:54Z

This can also be forced upon caddy via browser requests. Imagine a backend serving this simple php at localhost:8081 :

<?php
sleep(10);
phpinfo();
?>

And a simple Caddyfile like this:

:8080 {
        log / stdout "{host} {combined} {request_id}"
        errors stderr

        proxy / localhost:8081 {
                transparent
                policy least_conn
                keepalive 5
                fail_timeout 10s
                max_fails 1
                try_duration 1s
        }
}

Point your browser to http://localhost:8080 and wait for the phpinfo to be displayed - works.
Press F5 and while it's loading the ESC button -> you'll see [ERROR 502 /] context canceled message in the log.
Press F5 again within fail_timeout and you'll get 502 bad gateway and [ERROR 502 /] no hosts available upstream in the caddy log. This will persist until fail_timout has passed since the first fail. In the log of the backend (NGINX), I only get a HTTP 499.
2018-03-03T14:24:05+00:00 127.0.0.1 - - localhost/localhost "GET / HTTP/1.1" 499 4.048 374 0 29 1 "-" "-" "Mozilla/5.0 (X11; Linux x86_64; rv:58.0) Gecko/20100101 Firefox/58.0"
So it seems caddy is misinterpreting the client "error" for a backend error.

In my case I'm currently using a fail_timeout 0 as a workaround or else all my sites go down for fail_timeout.
@mholt This sounds pretty much exploitable for DDoS attacks, doesn't it?

Caddy Version: 0.10.11 (and build from git 5552dcb).

tobya · 2018-04-26T22:08:35Z

Is this still an issue in 0.10.14?

ionphractal · 2018-04-27T10:54:32Z

@tobya Just tested it and unfortunately yes, it is still present.

$ ./caddy -version       
Caddy 0.10.14 (non-commercial use only)
$ ./caddy -conf Caddyfile
Activating privacy features... done.
http://:8080
WARNING: File descriptor limit 1024 is too low for production servers. At least 8192 is recommended. Fix with "ulimit -n 8192".
localhost:8080 ::1 - - [27/Apr/2018:12:51:49 +0200] "GET /test.php HTTP/1.1" 200 27868 "-" "Mozilla/5.0 (X11; Linux x86_64; rv:59.0) Gecko/20100101 Firefox/59.0" 
27/Apr/2018:12:51:54 +0200 [ERROR 502 /test.php] context canceled
localhost:8080 ::1 - - [27/Apr/2018:12:51:54 +0200] "GET /test.php HTTP/1.1" 502 16 "-" "Mozilla/5.0 (X11; Linux x86_64; rv:59.0) Gecko/20100101 Firefox/59.0" 
27/Apr/2018:12:51:55 +0200 [ERROR 502 /test.php] no hosts available upstream
localhost:8080 ::1 - - [27/Apr/2018:12:51:55 +0200] "GET /test.php HTTP/1.1" 502 16 "-" "Mozilla/5.0 (X11; Linux x86_64; rv:59.0) Gecko/20100101 Firefox/59.0" 
27/Apr/2018:12:51:56 +0200 [ERROR 502 /test.php] no hosts available upstream

corny · 2018-05-11T11:12:09Z

I'm having the same issue with Caddy 0.11.0.

Homer-Sim · 2018-05-26T20:26:43Z

Having this issue too on 0.11.0

How can I solve or at least work around it?

tomasdeml · 2018-06-26T13:06:16Z

We stumbled upon this bug as well. Are there any plans to fix it? It has a devastating potential as it can be exploited for a DDoS attack...

mholt · 2018-06-26T14:49:13Z

@tomasdeml

It has a devastating potential as it can be exploited for a DDoS attack...

Do explain...

Bobris · 2018-06-26T15:40:46Z

@mholt: It is enough that one evil client will repeatly make request and immediately close connection and caddy will stop proxing for defined fail_timeout time. Even if you set max_fails higher than 1, only one client could easily do cancel that many requests in row. so it is not even DDoS, but more severe DoS attack.

mholt · 2018-06-26T16:42:42Z

Hmm, I see. Well, you could for now use fail_timeout of 0 if you're worried about attacks like that; but better would be to have this fixed. I don't have the time right now to do it, but I welcome pull requests, and help reviewing them to get them merged.

Bobris · 2018-06-26T22:45:34Z

Setting fail_timeout to 0 will make load balancing proxy useless (it will forward requests to truely failed nodes, all the time), so it is not really option.

mholt · 2018-06-26T22:46:31Z

I understand that. Feel free to open a pull request for quicker resolution!

magikstm · 2019-02-03T22:51:06Z

I suggest tagging this issue as "Bug".

Was original issue fixed by #2297?

mholt · 2019-02-03T22:58:09Z

Good point; yes, we seem to handle the context cancelled error specially now, so that it does not consider the backend to be down. I believe this is fixed.

STaRDoGG · 2019-04-19T04:17:05Z

I've been running into issues with Caddy 0.11.5 constantly stopping, and noticed a lot of these in my log files:

18/Apr/2019:22:44:46 -0500 [ERROR 499 /radarrdoc/signalr/connect] context canceled
18/Apr/2019:22:44:52 -0500 [ERROR 499 /lidarrdoc/signalr/poll] context canceled
18/Apr/2019:22:45:10 -0500 [ERROR 499 /sonarrdoc/signalr/poll] context canceled
18/Apr/2019:22:46:47 -0500 [ERROR 499 /lidarrdoc/signalr/poll] context canceled
18/Apr/2019:22:48:24 -0500 [ERROR 499 /lidarrdoc/signalr/poll] context canceled
18/Apr/2019:22:48:24 -0500 [ERROR 499 /lidarrdoc/signalr/abort] context canceled
18/Apr/2019:22:48:24 -0500 [ERROR 499 /sonarrdoc/signalr/poll] context canceled
18/Apr/2019:22:48:24 -0500 [ERROR 499 /radarrdoc/signalr/poll] context canceled
18/Apr/2019:22:49:56 -0500 [ERROR 499 /lidarrdoc/signalr/poll] context canceled
18/Apr/2019:22:51:44 -0500 [ERROR 499 /lidarrdoc/signalr/poll] context canceled
18/Apr/2019:22:57:44 -0500 [ERROR 499 /lidarrdoc/signalr/poll] context canceled
18/Apr/2019:22:58:07 -0500 [ERROR 499 /lidarrdoc/signalr/poll] context canceled

After a bunch of trial and error with the way I call PHP in my caddyfile it just keeps happening no matter how I call it, or what environment vars I use, which led me to stumbling upon this post. I tested with @ionphractal 's instructions and it seems to still be happening in this version of Caddy.

caddy
Activating privacy features... done.

Serving HTTP on port 8080
http://:8080

18/Apr/2019:23:10:33 -0500 [ERROR 502 /] dial tcp [::1]:8081: connectex: No connection could be made because the target machine actively refused it.
localhost:8080 ::1 - - [18/Apr/2019:23:10:33 -0500] "GET / HTTP/1.1" 502 16 "-" "Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/73.0.3683.103 Safari/537.36"
18/Apr/2019:23:10:34 -0500 [ERROR 502 /favicon.ico] no hosts available upstream
localhost:8080 ::1 - - [18/Apr/2019:23:10:34 -0500] "GET /favicon.ico HTTP/1.1" 502 16 "http://localhost:8080/" "Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/73.0.3683.103 Safari/537.36"
18/Apr/2019:23:10:36 -0500 [ERROR 502 /] no hosts available upstream
localhost:8080 ::1 - - [18/Apr/2019:23:10:36 -0500] "GET / HTTP/1.1" 502 16 "-" "Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/73.0.3683.103 Safari/537.36"
18/Apr/2019:23:10:39 -0500 [ERROR 502 /] no hosts available upstream
localhost:8080 ::1 - - [18/Apr/2019:23:10:39 -0500] "GET / HTTP/1.1" 502 16 "-" "Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/73.0.3683.103 Safari/537.36"
18/Apr/2019:23:10:40 -0500 [ERROR 502 /favicon.ico] no hosts available upstream
localhost:8080 ::1 - - [18/Apr/2019:23:10:40 -0500] "GET /favicon.ico HTTP/1.1" 502 16 "http://localhost:8080/" "Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/73.0.3683.103 Safari/537.36"
18/Apr/2019:23:10:41 -0500 [ERROR 502 /] no hosts available upstream
localhost:8080 ::1 - - [18/Apr/2019:23:10:41 -0500] "GET / HTTP/1.1" 502 16 "-" "Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/73.0.3683.103 Safari/537.36"
18/Apr/2019:23:10:43 -0500 [ERROR 499 /] context canceled
localhost:8080 ::1 - - [18/Apr/2019:23:10:43 -0500] "GET / HTTP/1.1" 499 5 "-" "Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/73.0.3683.103 Safari/537.36"
18/Apr/2019:23:10:45 -0500 [ERROR 499 /] context canceled
localhost:8080 ::1 - - [18/Apr/2019:23:10:45 -0500] "GET / HTTP/1.1" 499 5 "-" "Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/73.0.3683.103 Safari/537.36"
18/Apr/2019:23:10:47 -0500 [ERROR 499 /] context canceled
localhost:8080 ::1 - - [18/Apr/2019:23:10:47 -0500] "GET / HTTP/1.1" 499 5 "-" "Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/73.0.3683.103 Safari/537.36"
18/Apr/2019:23:10:49 -0500 [ERROR 499 /] context canceled
localhost:8080 ::1 - - [18/Apr/2019:23:10:49 -0500] "GET / HTTP/1.1" 499 5 "-" "Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/73.0.3683.103 Safari/537.36"
18/Apr/2019:23:10:51 -0500 [ERROR 499 /] context canceled
localhost:8080 ::1 - - [18/Apr/2019:23:10:51 -0500] "GET / HTTP/1.1" 499 5 "-" "Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/73.0.3683.103 Safari/537.36"
18/Apr/2019:23:10:53 -0500 [ERROR 499 /] context canceled
localhost:8080 ::1 - - [18/Apr/2019:23:10:53 -0500] "GET / HTTP/1.1" 499 5 "-" "Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/73.0.3683.103 Safari/537.36"
18/Apr/2019:23:10:56 -0500 [ERROR 499 /] context canceled
localhost:8080 ::1 - - [18/Apr/2019:23:10:56 -0500] "GET / HTTP/1.1" 499 5 "-" "Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/73.0.3683.103 Safari/537.36"

htfy96 mentioned this issue Jun 3, 2018

Caddy反代的ubuntu镜像经常502 sjtug/mirror-requests#19

Closed

Ranger-X mentioned this issue Sep 19, 2018

HTTP status 499 instead of 502's for 'Context canceled' 'errors' #2297

Merged

4 tasks

mholt closed this as completed Feb 3, 2019

mholt added the bug 🐞 Something isn't working label Feb 3, 2019

danlsgiga mentioned this issue Mar 13, 2019

http proxy error context canceled fabiolb/fabio#264

Closed

danlsgiga mentioned this issue Oct 20, 2020

500 error for probably cancelled request (must be 499) #3748

Closed

amir20 mentioned this issue Mar 23, 2024

Caddy v2 - issues with dozzle, continuous spamming log reading: context canceled amir20/dozzle#2844

Closed

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

context canceled and 502 #1925

context canceled and 502 #1925

rafales commented Oct 17, 2017

rafales commented Oct 17, 2017

ubergesundheit commented Oct 21, 2017

ionphractal commented Mar 3, 2018

tobya commented Apr 26, 2018

ionphractal commented Apr 27, 2018

corny commented May 11, 2018

Homer-Sim commented May 26, 2018 •

edited

Loading

tomasdeml commented Jun 26, 2018 •

edited

Loading

mholt commented Jun 26, 2018 •

edited

Loading

Bobris commented Jun 26, 2018 •

edited

Loading

mholt commented Jun 26, 2018

Bobris commented Jun 26, 2018

mholt commented Jun 26, 2018

magikstm commented Feb 3, 2019

mholt commented Feb 3, 2019

STaRDoGG commented Apr 19, 2019 •

edited

Loading

context canceled and 502 #1925

context canceled and 502 #1925

Comments

rafales commented Oct 17, 2017

1. What version of Caddy are you using (caddy -version)?

2. What are you trying to do?

3. What is your entire Caddyfile?

4. How did you run Caddy (give the full command and describe the execution environment)?

5. Please paste any relevant HTTP request(s) here.

6. What did you expect to see?

7. What did you see instead (give full error messages and/or log)?

rafales commented Oct 17, 2017

ubergesundheit commented Oct 21, 2017

ionphractal commented Mar 3, 2018

tobya commented Apr 26, 2018

ionphractal commented Apr 27, 2018

corny commented May 11, 2018

Homer-Sim commented May 26, 2018 • edited Loading

tomasdeml commented Jun 26, 2018 • edited Loading

mholt commented Jun 26, 2018 • edited Loading

Bobris commented Jun 26, 2018 • edited Loading

mholt commented Jun 26, 2018

Bobris commented Jun 26, 2018

mholt commented Jun 26, 2018

magikstm commented Feb 3, 2019

mholt commented Feb 3, 2019

STaRDoGG commented Apr 19, 2019 • edited Loading

1. What version of Caddy are you using (`caddy -version`)?

Homer-Sim commented May 26, 2018 •

edited

Loading

tomasdeml commented Jun 26, 2018 •

edited

Loading

mholt commented Jun 26, 2018 •

edited

Loading

Bobris commented Jun 26, 2018 •

edited

Loading

STaRDoGG commented Apr 19, 2019 •

edited

Loading