caddyserver/cache-handler

Missing response on cached paths

winstxnhdw opened this issue · 32 comments

winstxnhdw commented

Cache misses on first request and hits on next, that's fine. But I no longer receive a response from the endpoint.

This is my Caddyfile.

{
	order cache before rewrite
	cache
}

:{$APP_PORT} {
	handle_path /api/* {
		reverse_proxy http://localhost:{$SERVER_PORT} {
			transport http {
				versions h2c
			}
		}
	}

	handle_path /api/v1/translate {
		cache {
			allowed_http_verbs POST
			ttl 24h
		}
	}
}

Logs from cURL.

*   Trying [::1]:7861...
* Connected to localhost (::1) port 7861
> POST /api/v1/translate? HTTP/1.1
> Host: localhost:7861
> User-Agent: curl/8.3.0
> Accept: */*
> Content-Type: application/json
> Content-Length: 97
>
< HTTP/1.1 200 OK
HTTP/1.1 200 OK
< Cache-Control:
Cache-Control:
< Cache-Status: Souin; fwd=uri-miss; stored; key=POST-http-localhost:7861--718c30564a9d539ac393940896d588a095e1b2e1dea02edb7d36e62d9d40f757
Cache-Status: Souin; fwd=uri-miss; stored; key=POST-http-localhost:7861--718c30564a9d539ac393940896d588a095e1b2e1dea02edb7d36e62d9d40f757
< Server: Caddy
Server: Caddy
< Date: Tue, 19 Sep 2023 21:05:15 GMT
Date: Tue, 19 Sep 2023 21:05:15 GMT
< Content-Length: 0
Content-Length: 0

Logs from Caddy

{
  "level":"info","ts":1695157539.7626615,
  "logger":"http.handlers.cache",
  "msg":"Serve from cache &{Method:POST URL:? Proto:HTTP/1.1 ProtoMajor:1 ProtoMinor:1 Header:map[Accept:[*/*] Content-Length:[97] Content-Type:[application/json] Date:[Tue, 19 Sep 2023 21:05:39 UTC] User-Agent:[curl/8.3.0]] Body:{Reader:{\n         \"text\": \"world!\",\n         \"source\": \"eng_Latn\",\n         \"target\": \"spa_Latn\"\n      }} GetBody:<nil> ContentLength:97 TransferEncoding:[] Close:false Host:localhost:7861 Form:map[] PostForm:map[] MultipartForm:<nil> Trailer:map[] RemoteAddr:172.17.0.1:45620 RequestURI:/? TLS:<nil> Cancel:<nil> Response:<nil> ctx:0xc000201a40}"
}
hussam-almarzoq commented

hello @winstxnhdw,

were you able to solve this? I am also facing the same issue.

winstxnhdw commented

Hey,

No, I have not and can't find a solution anywhere. I read somewhere that the souin cache just doesn't cache POST requests. Seeing that this has been up for months and ignored, I guess this issue isn't a priority for them. I recommend you to move on or just use some middleware caching service.

francislavoie commented

@winstxnhdw I think your problem was with your config. You're using handle_path which makes the routes mutually exclusive (in other words, only the first matching one is run). Your translate handle only has the cache directive and nothing else, so all Caddy can do is serve an empty response for that route (because you didn't configure it to do anything else in that route).

Sorry this went unseen, I don't monitor this repo very much because I don't have the bandwidth to contribute to its development.

winstxnhdw commented

@francislavoie No need for apologies. I understand that you and your team are doing this voluntarily in your free time, and I am greatly appreciative of your work.

I gave it another attempt again, this time it returns a response but it isn't caching.

{
	order cache before rewrite
	cache
}

:{$APP_PORT} {
	handle_path /api/* {
		@translate path /api/v1/translate
		handle @translate {
			cache {
				allowed_http_verbs POST
				ttl 24h
			}
		}

		reverse_proxy http://localhost:{$SERVER_PORT} {
			transport http {
				versions h2c
			}
		}
	}
}
francislavoie commented

This time the problem is that you stripped /api with the outer handle_path so it doesn't exist to match for the inner ones. Use handle instead for the outer one, or remove /api from the front of the inner ones. Also you don't need a named matcher for a simple path matcher (your inner one) so you can inline that to save a line.

winstxnhdw commented

Welp, I tried both suggestions, and now I can't get a successful response on any route. At least, it's hitting souin this time.

{
	order cache before rewrite
	cache
}

:{$APP_PORT} {
	handle /api/* {
		handle /api/v1/translate {
			cache {
				allowed_http_verbs POST
				ttl 24h
			}
		}

		reverse_proxy http://localhost:{$SERVER_PORT} {
			transport http {
				versions h2c
			}
		}
	}
}

It keeps returning these headers and every request returns a 404.

 cache-status: Souin; fwd=uri-miss; key=POST-http-localhost:7860-/api/v1/translate-34ac45d01c652cbba64508040284a24732dffdb3bc00a0900e078bb38ab44b99; detail=SERVE-HTTP-ERROR  content-length: 0  date: Thu,28 Dec 2023 22:20:30 GMT  server: Caddy
francislavoie commented

A 404 means your upstream is writing the response (Caddy wouldn't respond with 404 of its own volition). You're now no longer stripping /api from the request path, so if your upstream expects /api to not exist then that may be your problem.

This doesn't look like an issue with cache at all at this point so I think this issue can probably be closed.

winstxnhdw commented

Ahh, I see. That makes a lot more sense. Thanks for the help. We can close it.

winstxnhdw commented

You're now no longer stripping /api from the request path, so if your upstream expects /api to not exist then that may be your problem.

Sorry for coming back to this but I gave it a lot of thought, and you're right that my upstream expects /api to not exist. It's the general practice of how we handle stripped path prefixes in FastAPI. But since that's the case, isn't my 2nd attempt correct then?

{
	order cache before rewrite
	cache
}

:{$APP_PORT} {
	handle_path /api/* {
		handle /api/v1/translate {
			cache {
				allowed_http_verbs POST
				ttl 24h
			}
		}

		reverse_proxy http://localhost:{$SERVER_PORT} {
			transport http {
				versions h2c
			}
		}
	}
}

Here, I am stripping /api from the request path. And like I said earlier, I get a 200 response but no caching. Doesn't this mean there's still a problem with cache?

Unless, of course, you mean that cache won't work unless upstream expects the /api prefix.

EDIT:

So my guess was right, I even removed my server's path prefix and used the / path directly and I am getting the same issue as before where Caddy is not forwarding my request to the server (Body length of 0).

winstxnhdw commented

Yeah, I have removed everything and tried with a barebones config and server.

{
	order cache before rewrite
	cache
}

:{$APP_PORT} {
	cache {
		allowed_http_verbs GET POST
		ttl 24h
	}

	reverse_proxy http://localhost:{$SERVER_PORT}
}

The cache plugin just isn't able to cache POST request. Obviously, it can cache the GET endpoints though.

Here's the response headers for the POST request.

 cache-status: Souin; fwd=uri-miss; key=POST-http-localhost:7860-/v1/translate-34ac45d01c652cbba64508040284a24732dffdb3bc00a0900e078bb38ab44b99; detail=SERVE-HTTP-ERROR  content-length: 0  date: Fri,29 Dec 2023 13:46:23 GMT  server: Caddy

Here's the response headers for the GET request.

age: 5  cache-control:   cache-status: Souin; hit; ttl=86395; key=GET-http-localhost:7860-/v1/  content-length: 25  content-type: text/plain; charset=utf-8  date: Fri,29 Dec 2023 13:46:11 GMT  server: Caddy,hypercorn-h11
darkweak commented

@winstxnhdw here is a tiny snippet that works

localhost:80 {
	handle_path /api/* {
		handle /api/v1/translate {
			cache {
				allowed_http_verbs POST
				ttl 24h
			}
		}

		reverse_proxy https://google.com {
			transport http {
				versions h2c
			}
		}
	}
}

if I send a curl request to `http://localhost/api/api/v1/translate`
curl -X POST -i -k http://localhost/api/api/v1/translate

HTTP/1.1 404 Not Found
Cache-Control: 
Cache-Status: Souin; fwd=uri-miss; stored; key=POST-http-localhost-/api/v1/translate
Content-Length: 1577
Content-Type: text/html; charset=UTF-8
Date: Fri, 29 Dec 2023 13:52:40 GMT
Referrer-Policy: no-referrer
Server: Caddy

<!DOCTYPE html>
<html lang=en>
  <meta charset=utf-8>
  <meta name=viewport content="initial-scale=1, minimum-scale=1, width=device-width">
  <title>Error 404 (Not Found)!!1</title>
  <style>
    *{margin:0;padding:0}html,code{font:15px/22px arial,sans-serif}html{background:#fff;color:#222;padding:15px}body{margin:7% auto 0;max-width:390px;min-height:180px;padding:30px 0 15px}* > body{background:url(//www.google.com/images/errors/robot.png) 100% 5px no-repeat;padding-right:205px}p{margin:11px 0 22px;overflow:hidden}ins{color:#777;text-decoration:none}a img{border:0}@media screen and (max-width:772px){body{background:none;margin-top:0;max-width:none;padding-right:0}}#logo{background:url(//www.google.com/images/branding/googlelogo/1x/googlelogo_color_150x54dp.png) no-repeat;margin-left:-5px}@media only screen and (min-resolution:192dpi){#logo{background:url(//www.google.com/images/branding/googlelogo/2x/googlelogo_color_150x54dp.png) no-repeat 0% 0%/100% 100%;-moz-border-image:url(//www.google.com/images/branding/googlelogo/2x/googlelogo_color_150x54dp.png) 0}}@media only screen and (-webkit-min-device-pixel-ratio:2){#logo{background:url(//www.google.com/images/branding/googlelogo/2x/googlelogo_color_150x54dp.png) no-repeat;-webkit-background-size:100% 100%}}#logo{display:inline-block;height:54px;width:150px}
  </style>
  <a href=//www.google.com/><span id=logo aria-label=Google></span></a>
  <p><b>404.</b> <ins>That’s an error.</ins>
  <p>The requested URL <code>/api/v1/translate</code> was not found on this server.  <ins>That’s all we know.</ins>

curl -X POST -i -k http://localhost/api/api/v1/translate

HTTP/1.1 404 Not Found
Age: 3
Cache-Control: 
Cache-Status: Souin; hit; ttl=86397; key=POST-http-localhost-/api/v1/translate
Content-Length: 1577
Content-Type: text/html; charset=UTF-8
Date: Fri, 29 Dec 2023 13:52:40 GMT
Referrer-Policy: no-referrer
Server: Caddy

<!DOCTYPE html>
<html lang=en>
  <meta charset=utf-8>
  <meta name=viewport content="initial-scale=1, minimum-scale=1, width=device-width">
  <title>Error 404 (Not Found)!!1</title>
  <style>
    *{margin:0;padding:0}html,code{font:15px/22px arial,sans-serif}html{background:#fff;color:#222;padding:15px}body{margin:7% auto 0;max-width:390px;min-height:180px;padding:30px 0 15px}* > body{background:url(//www.google.com/images/errors/robot.png) 100% 5px no-repeat;padding-right:205px}p{margin:11px 0 22px;overflow:hidden}ins{color:#777;text-decoration:none}a img{border:0}@media screen and (max-width:772px){body{background:none;margin-top:0;max-width:none;padding-right:0}}#logo{background:url(//www.google.com/images/branding/googlelogo/1x/googlelogo_color_150x54dp.png) no-repeat;margin-left:-5px}@media only screen and (min-resolution:192dpi){#logo{background:url(//www.google.com/images/branding/googlelogo/2x/googlelogo_color_150x54dp.png) no-repeat 0% 0%/100% 100%;-moz-border-image:url(//www.google.com/images/branding/googlelogo/2x/googlelogo_color_150x54dp.png) 0}}@media only screen and (-webkit-min-device-pixel-ratio:2){#logo{background:url(//www.google.com/images/branding/googlelogo/2x/googlelogo_color_150x54dp.png) no-repeat;-webkit-background-size:100% 100%}}#logo{display:inline-block;height:54px;width:150px}
  </style>
  <a href=//www.google.com/><span id=logo aria-label=Google></span></a>
  <p><b>404.</b> <ins>That’s an error.</ins>
  <p>The requested URL <code>/api/v1/translate</code> was not found on this server.  <ins>That’s all we know.</ins>

But if I send on the http://localhost/api/v1/translate url it doesn't go through the handle /api/v1/translate directive. handle_path strips the /api prefix.

I will try with https.

winstxnhdw commented

Yeap, but the problem is consistent without the prefixes as well.

darkweak commented

@winstxnhdw

curl -X POST -i -k https://localhost/api/v1/translate

HTTP/2 404 
alt-svc: h3=":443"; ma=2592000
content-type: text/html; charset=UTF-8
date: Fri, 29 Dec 2023 13:57:37 GMT
referrer-policy: no-referrer
server: Caddy
content-length: 1573

<!DOCTYPE html>
<html lang=en>
  <meta charset=utf-8>
  <meta name=viewport content="initial-scale=1, minimum-scale=1, width=device-width">
  <title>Error 404 (Not Found)!!1</title>
  <style>
    *{margin:0;padding:0}html,code{font:15px/22px arial,sans-serif}html{background:#fff;color:#222;padding:15px}body{margin:7% auto 0;max-width:390px;min-height:180px;padding:30px 0 15px}* > body{background:url(//www.google.com/images/errors/robot.png) 100% 5px no-repeat;padding-right:205px}p{margin:11px 0 22px;overflow:hidden}ins{color:#777;text-decoration:none}a img{border:0}@media screen and (max-width:772px){body{background:none;margin-top:0;max-width:none;padding-right:0}}#logo{background:url(//www.google.com/images/branding/googlelogo/1x/googlelogo_color_150x54dp.png) no-repeat;margin-left:-5px}@media only screen and (min-resolution:192dpi){#logo{background:url(//www.google.com/images/branding/googlelogo/2x/googlelogo_color_150x54dp.png) no-repeat 0% 0%/100% 100%;-moz-border-image:url(//www.google.com/images/branding/googlelogo/2x/googlelogo_color_150x54dp.png) 0}}@media only screen and (-webkit-min-device-pixel-ratio:2){#logo{background:url(//www.google.com/images/branding/googlelogo/2x/googlelogo_color_150x54dp.png) no-repeat;-webkit-background-size:100% 100%}}#logo{display:inline-block;height:54px;width:150px}
  </style>
  <a href=//www.google.com/><span id=logo aria-label=Google></span></a>
  <p><b>404.</b> <ins>That’s an error.</ins>
  <p>The requested URL <code>/v1/translate</code> was not found on this server.  <ins>That’s all we know.</ins>


curl -X POST -i -k https://localhost/api/v1/translate

HTTP/2 404 
alt-svc: h3=":443"; ma=2592000
content-type: text/html; charset=UTF-8
date: Fri, 29 Dec 2023 13:57:41 GMT
referrer-policy: no-referrer
server: Caddy
content-length: 1573

<!DOCTYPE html>
<html lang=en>
  <meta charset=utf-8>
  <meta name=viewport content="initial-scale=1, minimum-scale=1, width=device-width">
  <title>Error 404 (Not Found)!!1</title>
  <style>
    *{margin:0;padding:0}html,code{font:15px/22px arial,sans-serif}html{background:#fff;color:#222;padding:15px}body{margin:7% auto 0;max-width:390px;min-height:180px;padding:30px 0 15px}* > body{background:url(//www.google.com/images/errors/robot.png) 100% 5px no-repeat;padding-right:205px}p{margin:11px 0 22px;overflow:hidden}ins{color:#777;text-decoration:none}a img{border:0}@media screen and (max-width:772px){body{background:none;margin-top:0;max-width:none;padding-right:0}}#logo{background:url(//www.google.com/images/branding/googlelogo/1x/googlelogo_color_150x54dp.png) no-repeat;margin-left:-5px}@media only screen and (min-resolution:192dpi){#logo{background:url(//www.google.com/images/branding/googlelogo/2x/googlelogo_color_150x54dp.png) no-repeat 0% 0%/100% 100%;-moz-border-image:url(//www.google.com/images/branding/googlelogo/2x/googlelogo_color_150x54dp.png) 0}}@media only screen and (-webkit-min-device-pixel-ratio:2){#logo{background:url(//www.google.com/images/branding/googlelogo/2x/googlelogo_color_150x54dp.png) no-repeat;-webkit-background-size:100% 100%}}#logo{display:inline-block;height:54px;width:150px}
  </style>
  <a href=//www.google.com/><span id=logo aria-label=Google></span></a>
  <p><b>404.</b> <ins>That’s an error.</ins>
  <p>The requested URL <code>/v1/translate</code> was not found on this server.  <ins>That’s all we know.</ins>


curl -X POST -i -k https://localhost/api/api/v1/translate

HTTP/2 404 
alt-svc: h3=":443"; ma=2592000
cache-control: 
cache-status: Souin; fwd=uri-miss; stored; key=POST-https-localhost-/api/v1/translate
content-type: text/html; charset=UTF-8
date: Fri, 29 Dec 2023 13:58:23 GMT
referrer-policy: no-referrer
server: Caddy
content-length: 1577

<!DOCTYPE html>
<html lang=en>
  <meta charset=utf-8>
  <meta name=viewport content="initial-scale=1, minimum-scale=1, width=device-width">
  <title>Error 404 (Not Found)!!1</title>
  <style>
    *{margin:0;padding:0}html,code{font:15px/22px arial,sans-serif}html{background:#fff;color:#222;padding:15px}body{margin:7% auto 0;max-width:390px;min-height:180px;padding:30px 0 15px}* > body{background:url(//www.google.com/images/errors/robot.png) 100% 5px no-repeat;padding-right:205px}p{margin:11px 0 22px;overflow:hidden}ins{color:#777;text-decoration:none}a img{border:0}@media screen and (max-width:772px){body{background:none;margin-top:0;max-width:none;padding-right:0}}#logo{background:url(//www.google.com/images/branding/googlelogo/1x/googlelogo_color_150x54dp.png) no-repeat;margin-left:-5px}@media only screen and (min-resolution:192dpi){#logo{background:url(//www.google.com/images/branding/googlelogo/2x/googlelogo_color_150x54dp.png) no-repeat 0% 0%/100% 100%;-moz-border-image:url(//www.google.com/images/branding/googlelogo/2x/googlelogo_color_150x54dp.png) 0}}@media only screen and (-webkit-min-device-pixel-ratio:2){#logo{background:url(//www.google.com/images/branding/googlelogo/2x/googlelogo_color_150x54dp.png) no-repeat;-webkit-background-size:100% 100%}}#logo{display:inline-block;height:54px;width:150px}
  </style>
  <a href=//www.google.com/><span id=logo aria-label=Google></span></a>
  <p><b>404.</b> <ins>That’s an error.</ins>
  <p>The requested URL <code>/api/v1/translate</code> was not found on this server.  <ins>That’s all we know.</ins>


curl -X POST -i -k https://localhost/api/api/v1/translate

HTTP/2 404 
age: 3
alt-svc: h3=":443"; ma=2592000
cache-control: 
cache-status: Souin; hit; ttl=86397; key=POST-https-localhost-/api/v1/translate
content-type: text/html; charset=UTF-8
date: Fri, 29 Dec 2023 13:58:23 GMT
referrer-policy: no-referrer
server: Caddy
content-length: 1577

<!DOCTYPE html>
<html lang=en>
  <meta charset=utf-8>
  <meta name=viewport content="initial-scale=1, minimum-scale=1, width=device-width">
  <title>Error 404 (Not Found)!!1</title>
  <style>
    *{margin:0;padding:0}html,code{font:15px/22px arial,sans-serif}html{background:#fff;color:#222;padding:15px}body{margin:7% auto 0;max-width:390px;min-height:180px;padding:30px 0 15px}* > body{background:url(//www.google.com/images/errors/robot.png) 100% 5px no-repeat;padding-right:205px}p{margin:11px 0 22px;overflow:hidden}ins{color:#777;text-decoration:none}a img{border:0}@media screen and (max-width:772px){body{background:none;margin-top:0;max-width:none;padding-right:0}}#logo{background:url(//www.google.com/images/branding/googlelogo/1x/googlelogo_color_150x54dp.png) no-repeat;margin-left:-5px}@media only screen and (min-resolution:192dpi){#logo{background:url(//www.google.com/images/branding/googlelogo/2x/googlelogo_color_150x54dp.png) no-repeat 0% 0%/100% 100%;-moz-border-image:url(//www.google.com/images/branding/googlelogo/2x/googlelogo_color_150x54dp.png) 0}}@media only screen and (-webkit-min-device-pixel-ratio:2){#logo{background:url(//www.google.com/images/branding/googlelogo/2x/googlelogo_color_150x54dp.png) no-repeat;-webkit-background-size:100% 100%}}#logo{display:inline-block;height:54px;width:150px}
  </style>
  <a href=//www.google.com/><span id=logo aria-label=Google></span></a>
  <p><b>404.</b> <ins>That’s an error.</ins>
  <p>The requested URL <code>/api/v1/translate</code> was not found on this server.  <ins>That’s all we know.</ins>
darkweak commented

Your reverse_proxy is throwing an error I guess. Run with the debug global config and paste your logs please.

winstxnhdw commented

If the issue is the reverse proxy, my /v1 endpoint should be broken as well, but it isn't.

{
  "level": "debug",
  "ts": 1703858584.7142282,
  "logger": "http.handlers.reverse_proxy",
  "msg": "upstream roundtrip",
  "upstream": "localhost:5000",
  "duration": 0.00024129,
  "request": {
    "remote_ip": "172.46.0.1",
    "remote_port": "40140",
    "client_ip": "172.46.0.1",
    "proto": "HTTP/1.1",
    "method": "POST",
    "host": "localhost:7860",
    "uri": "/v1/translate",
    "headers": {
      "Sec-Fetch-Site": [
        "same-origin"
      ],
      "Referer": [
        "http://localhost:7860/docs"
      ],
      "Accept": [
        "application/json"
      ],
      "Sec-Fetch-Mode": [
        "cors"
      ],
      "X-Forwarded-For": [
        "172.46.0.1"
      ],
      "X-Forwarded-Proto": [
        "http"
      ],
      "Sec-Fetch-Dest": [
        "empty"
      ],
      "Dnt": [
        "1"
      ],
      "Origin": [
        "http://localhost:7860"
      ],
      "User-Agent": [
        "Mozilla/5.0 (X11; Linux x86_64; rv:122.0) Gecko/20100101 Firefox/122.0"
      ],
      "Accept-Encoding": [
        "gzip, deflate, br"
      ],
      "Content-Length": [
        "77"
      ],
      "X-Forwarded-Host": [
        "localhost:7860"
      ],
      "Content-Type": [
        "application/json"
      ],
      "Date": [
        "Fri, 29 Dec 2023 14:03:04 UTC"
      ]
    }
  },
  "error": "net/http: HTTP/1.x transport connection broken: http: ContentLength=77 with Body length 0"
}
{
  "level": "error",
  "ts": 1703858584.7142594,
  "logger": "http.log.error",
  "msg": "net/http: HTTP/1.x transport connection broken: http: ContentLength=77 with Body length 0",
  "request": {
    "remote_ip": "172.46.0.1",
    "remote_port": "40140",
    "client_ip": "172.46.0.1",
    "proto": "HTTP/1.1",
    "method": "POST",
    "host": "localhost:7860",
    "uri": "/v1/translate",
    "headers": {
      "Content-Length": [
        "77"
      ],
      "Origin": [
        "http://localhost:7860"
      ],
      "Dnt": [
        "1"
      ],
      "Accept": [
        "application/json"
      ],
      "Referer": [
        "http://localhost:7860/docs"
      ],
      "Connection": [
        "keep-alive"
      ],
      "Sec-Fetch-Mode": [
        "cors"
      ],
      "Content-Type": [
        "application/json"
      ],
      "Sec-Fetch-Dest": [
        "empty"
      ],
      "User-Agent": [
        "Mozilla/5.0 (X11; Linux x86_64; rv:122.0) Gecko/20100101 Firefox/122.0"
      ],
      "Accept-Encoding": [
        "gzip, deflate, br"
      ],
      "Sec-Fetch-Site": [
        "same-origin"
      ]
    }
  },
  "duration": 0.000405558,
  "status": 502,
  "err_id": "vnkn7adqz",
  "err_trace": "reverseproxy.statusError (reverseproxy.go:1267)"
}
{
  "level": "debug",
  "ts": 1703858584.7138925,
  "logger": "http.handlers.cache",
  "msg": "Incomming request &{Method:POST URL:/v1/translate Proto:HTTP/1.1 ProtoMajor:1 ProtoMinor:1 Header:map[Accept:[application/json] Accept-Encoding:[gzip, deflate, br] Connection:[keep-alive] Content-Length:[77] Content-Type:[application/json] Dnt:[1] Origin:[http://localhost:7860] Referer:[http://localhost:7860/docs] Sec-Fetch-Dest:[empty] Sec-Fetch-Mode:[cors] Sec-Fetch-Site:[same-origin] User-Agent:[Mozilla/5.0 (X11; Linux x86_64; rv:122.0) Gecko/20100101 Firefox/122.0]] Body:0xc00037a200 GetBody:<nil> ContentLength:77 TransferEncoding:[] Close:false Host:localhost:7860 Form:map[] PostForm:map[] MultipartForm:<nil> Trailer:map[] RemoteAddr:172.46.0.1:40140 RequestURI:/v1/translate TLS:<nil> Cancel:<nil> Response:<nil> ctx:0xc0001baa80}"
}
{
  "level": "debug",
  "ts": 1703858584.7139294,
  "logger": "http.handlers.cache",
  "msg": "Request cache-control &{MaxAge:-1 MaxStale:-1 MaxStaleSet:false MinFresh:-1 NoCache:false NoStore:false NoTransform:false OnlyIfCached:false StaleIfError:0 Extensions:[]}"
}
{
  "level": "debug",
  "ts": 1703858584.7139454,
  "logger": "http.handlers.cache",
  "msg": "Request the upstream server"
}

Raw logs

{"level":"debug","ts":1703859197.1497703,"logger":"http.handlers.cache","msg":"Incomming request &{Method:POST URL:/v1/translate Proto:HTTP/1.1 ProtoMajor:1 ProtoMinor:1 Header:map[Accept:[application/json] Accept-Encoding:[gzip, deflate, br] Connection:[keep-alive] Content-Length:[77] Content-Type:[application/json] Dnt:[1] Origin:[http://localhost:7860] Referer:[http://localhost:7860/docs] Sec-Fetch-Dest:[empty] Sec-Fetch-Mode:[cors] Sec-Fetch-Site:[same-origin] User-Agent:[Mozilla/5.0 (X11; Linux x86_64; rv:122.0) Gecko/20100101 Firefox/122.0]] Body:0xc00037a340 GetBody:<nil> ContentLength:77 TransferEncoding:[] Close:false Host:localhost:7860 Form:map[] PostForm:map[] MultipartForm:<nil> Trailer:map[] RemoteAddr:172.46.0.1:43384 RequestURI:/v1/translate TLS:<nil> Cancel:<nil> Response:<nil> ctx:0xc0001978c0}"}
{"level":"debug","ts":1703859197.1498468,"logger":"http.handlers.cache","msg":"Request cache-control &{MaxAge:-1 MaxStale:-1 MaxStaleSet:false MinFresh:-1 NoCache:false NoStore:false NoTransform:false OnlyIfCached:false StaleIfError:0 Extensions:[]}"}
{"level":"debug","ts":1703859197.1498682,"logger":"http.handlers.cache","msg":"Request the upstream server"}
{"level":"debug","ts":1703859197.1498923,"logger":"http.handlers.reverse_proxy","msg":"selected upstream","dial":"localhost:5000","total_upstreams":1}
{"level":"debug","ts":1703859197.1501613,"logger":"http.handlers.reverse_proxy","msg":"upstream roundtrip","upstream":"localhost:5000","duration":0.000242517,"request":{"remote_ip":"172.46.0.1","remote_port":"43384","client_ip":"172.46.0.1","proto":"HTTP/1.1","method":"POST","host":"localhost:7860","uri":"/v1/translate","headers":{"User-Agent":["Mozilla/5.0 (X11; Linux x86_64; rv:122.0) Gecko/20100101 Firefox/122.0"],"Accept-Encoding":["gzip, deflate, br"],"Accept":["application/json"],"Sec-Fetch-Dest":["empty"],"Date":["Fri, 29 Dec 2023 14:13:17 UTC"],"Referer":["http://localhost:7860/docs"],"Content-Type":["application/json"],"Sec-Fetch-Mode":["cors"],"Sec-Fetch-Site":["same-origin"],"X-Forwarded-Proto":["http"],"Origin":["http://localhost:7860"],"Content-Length":["77"],"Dnt":["1"],"X-Forwarded-For":["172.46.0.1"],"X-Forwarded-Host":["localhost:7860"]}},"error":"net/http: HTTP/1.x transport connection broken: http: ContentLength=77 with Body length 0"}
{"level":"error","ts":1703859197.150199,"logger":"http.log.error","msg":"net/http: HTTP/1.x transport connection broken: http: ContentLength=77 with Body length 0","request":{"remote_ip":"172.46.0.1","remote_port":"43384","client_ip":"172.46.0.1","proto":"HTTP/1.1","method":"POST","host":"localhost:7860","uri":"/v1/translate","headers":{"Referer":["http://localhost:7860/docs"],"Content-Length":["77"],"Connection":["keep-alive"],"Dnt":["1"],"Sec-Fetch-Mode":["cors"],"Sec-Fetch-Site":["same-origin"],"User-Agent":["Mozilla/5.0 (X11; Linux x86_64; rv:122.0) Gecko/20100101 Firefox/122.0"],"Accept-Encoding":["gzip, deflate, br"],"Content-Type":["application/json"],"Origin":["http://localhost:7860"],"Sec-Fetch-Dest":["empty"],"Accept":["application/json"]}},"duration":0.000456767,"status":502,"err_id":"4wkas21tp","err_trace":"reverseproxy.statusError (reverseproxy.go:1267)"}
[2023-12-29 14:13:17 +0000] [36] [INFO] - "POST /v1/translate 1.1" 127.0.0.1:54432 "Mozilla/5.0 (X11; Linux x86_64; rv:122.0) Gecko/20100101 Firefox/122.0"
[2023-12-29 14:13:17 +0000] [36] [INFO] 400 "POST /v1/translate 1.1" 127.0.0.1:54432 "Mozilla/5.0 (X11; Linux x86_64; rv:122.0) Gecko/20100101 Firefox/122.0"

If you are curious, this is the body of the request.

{
  "text": "Hello, world!",
  "source": "eng_Latn",
  "target": "spa_Latn"
}
darkweak commented

net/http: HTTP/1.x transport connection broken: http: ContentLength=77 with Body length 0 that's the error from your logs.

francislavoie commented

No, this doesn't work:

	handle_path /api/* {
		handle /api/v1/translate {

Because handle_path rewrites the request path to remove /api, so the path is now only /v1/translate so /api/v1/translate does not match.

winstxnhdw commented

Yeah, that's because Caddy isn't forwarding anything to my endpoint. If I bypass Caddy and call the endpoint directly, I get a response. Also, this only happens when I use the cache plugin. All is good without it. Does Caddy with cache transform the request body in such a way that my web server can no longer handle?

darkweak commented

You're probably right, I will check if the body is put again in the request after we read it to generate the body hash.

  • 👍1
francislavoie commented

That error reads to me like the cache module consumed the request body, then the proxy also tries to read it to stream it upstream, but it's not able to because the body is already consumed.

@darkweak how is the cache module using the request body? If you're using it, you must wrap/buffer it so that it can be rewinded and reused later.

winstxnhdw commented

My guess is that after copying, the original req.Body's pointer is now at the end of the stream, so you are just giving req.Body an empty stream.

You can try this instead?

req.Body = io.NopCloser(bytes.NewReader(b.Bytes()))

Looks similar to this issue.

darkweak commented

I probably found a hack for that @winstxnhdw darkweak/souin@ddc8190 (cc @francislavoie can you review the patch please? 🙏)

darkweak commented

@winstxnhdw can you try the new pushed version xcaddy build --with github.com/darkweak/souin/plugins/caddy@ddc819000fa55599f9dad20e150902cfd46322f3 --with github.com/darkweak/souin@ddc819000fa55599f9dad20e150902cfd46322f3?

winstxnhdw commented

@darkweak yup, it's finally working!

  • ❤️2
mholt commented

Nice work @darkweak :D

  • ❤️1
winstxnhdw commented

Do we know when caddyserver/cache-handler will be bumped to v1.6.45

darkweak commented

@winstxnhdw I hope this week 🤞 Meanwhile you can use darkweak/souin/plugins/caddy.

  • 👍1
  • 👀1
charsleysa commented

@darkweak any chance we'll get a release soon?

darkweak/souin/plugins/caddy seems broken.

  • 👍1
darkweak commented

Today! First we have to merge 2 PRs before tag the new version on Souin and bump the version in the go.mod in this repository 🙂

  • 🎉1
darkweak commented

@charsleysa released on souin repository and on the cache-handler, everything should work as expected. :)

charsleysa commented

Awesome! Thanks!