cache-handler icon indicating copy to clipboard operation
cache-handler copied to clipboard

HEAD Request HTTP/2 content-length error

Open alistairjevans opened this issue 1 year ago • 12 comments

I've seen fairly easily reproducible behaviour with HEAD requests where if caching is enabled on HEAD requests I get a HTTP/2 stream error:

* TLSv1.3 (IN), TLS handshake, Newsession Ticket (4):
* Connection state changed (MAX_CONCURRENT_STREAMS == 250)!
* http2 error: Invalid HTTP header field was received: frame type: 1, stream: 1, name: [content-length], value: []
* HTTP/2 stream 0 was not closed cleanly: PROTOCOL_ERROR (err 1)
* stopped the pause stream!

If I turn off HEAD caching with allowed_http_verbs GET, requests go through fine.

No errors in the caddy logs themselves. Any chance this handler is duplicating content-length headers?

alistairjevans avatar Nov 13 '24 13:11 alistairjevans

Hey @alistairjevans thank you for your feedback. Do you have a configuration to reproduce that? I'm trying with the given configuration without any issue.

# Caddyfile
{
    debug
    cache {
        ttl 1000s
    }
}

localhost {
    route {
        cache
        respond "Hello world!"
    }
}
> curl https://localhost/default --head
HTTP/2 200 
alt-svc: h3=":443"; ma=2592000
cache-control: 
cache-status: Souin; fwd=uri-miss; stored; key=HEAD-https-localhost-/default
content-type: text/plain; charset=utf-8
server: Caddy
content-length: 12
date: Thu, 14 Nov 2024 20:29:55 GMT

> curl https://localhost/default --head
HTTP/2 200 
age: 1
alt-svc: h3=":443"; ma=2592000
cache-control: 
cache-status: Souin; hit; ttl=999; key=HEAD-https-localhost-/default; detail=DEFAULT
content-type: text/plain; charset=utf-8
date: Thu, 14 Nov 2024 20:29:55 GMT
server: Caddy
content-length: 12

darkweak avatar Nov 14 '24 20:11 darkweak

Hi @darkweak; some details adjusted for privacy, but this is basically the config; nothing too complicated:


{
    on_demand_tls
    servers {
        metrics
    }
    cache {
        cache_name sc
    }
}

# Catch-all for any domain
:443 {
    tls {
        on_demand
    }

    cache {
      key {
       hide
       headers Accept-Language
      }
      mode bypass_request
    }

    # Reverse proxy to our app
    reverse_proxy https://myhost.example.com {
        header_up Host {upstream_hostport}
        header_up X-Real-IP {http.request.remote.host}
    }
}

This is proxying to a Rails app, running on Rack. Interestingly, when I perform a HEAD request directly to our app, I get a content-length header of '0' returned; with a GET this page would return content. Again some details omitted:

curl --head https://myhost.example.com
HTTP/2 200
alt-svc: h3=":443"; ma=2592000
cache-control: max-age=0, public, s-maxage=3, stale-while-revalidate=3
content-type: text/html; charset=utf-8
date: Thu, 14 Nov 2024 20:39:02 GMT
referrer-policy: strict-origin-when-cross-origin
server: Caddy
server: nginx
strict-transport-security: max-age=63113904; includeSubDomains; preload
vary: Accept
x-content-type-options: nosniff
x-download-options: noopen
x-permitted-cross-domain-policies: none
x-request-id: 42767e6f-8191-4eca-849f-ece005894173
x-runtime: 0.172931
x-xss-protection: 0
content-length: 0

Is it related to the 0 content-length response possibly?

alistairjevans avatar Nov 14 '24 20:11 alistairjevans

@alistairjevans Thanks, I tries to reproduce but unfortunately it worked well during my tests. I checked more about Rack and RoR (I'm not a RoR dev so that's new to me) and I think that's the streaming response (or something related to RoR/Rack).

FYI: I DM'ed you on Twitter/X if you don't want to send some sensitive data here if needed.

Thank you for your time for answering to my questions.

darkweak avatar Nov 15 '24 17:11 darkweak

This issue looks exactly like my previous issue #104

Which version of souin are you using?

imlonghao avatar Dec 10 '24 14:12 imlonghao

Hi @imlonghao, I'm on 0.15.0 of cache-handler; does that pull in the right Souin version to include your fix?

RUN xcaddy build \
    --with github.com/pberkel/[email protected] \
    --with github.com/caddyserver/[email protected] \
    --with github.com/darkweak/storages/go-redis/caddy \
    --with github.com/aksdb/[email protected]

alistairjevans avatar Dec 10 '24 14:12 alistairjevans

I tried your build command with my previous example, works well in my cases.

github.com/caddyserver/[email protected] included my fix as it required github.com/darkweak/souin v1.7.5

I don't mean to be offense, but how did you manage your image version? Did you just change the Dockerfile then run docker compose up -d, forgot running docker compose build? Maybe?

imlonghao avatar Dec 10 '24 15:12 imlonghao

This container is deployed into production via CI docker builds and pulled onto each host before the docker swarm deploy.

Not saying it's impossible something has broken here, just that it's unlikely. When I get a chance I'll manually check the build versions on the running container to double check.

alistairjevans avatar Dec 10 '24 15:12 alistairjevans

Can confirm both 0.15.0 of cache-handler and 1.7.5 of souin are running in that container, care of caddy build-info.

If you're confident there's no other path that can cause this failure @imlonghao, I'll try enabling HEAD caching again in case the container got updated correctly since I last checked.

alistairjevans avatar Dec 10 '24 15:12 alistairjevans

@alistairjevans can you run with verbose and paste the logs? Did you find time to work on a reproducible repository?

darkweak avatar Dec 24 '24 15:12 darkweak

Apologies, I haven't found time to get back to this issue; will try to do so in the coming weeks. The issue may be moot though if #114 isn't fixed, because we'll have to change caching proxy entirely.

alistairjevans avatar Jan 02 '25 06:01 alistairjevans

I'm getting UPSTREAM-ERROR-OR-EMPTY-RESPONSE for all HEAD requests (GET works just fine).

$ curl https://ysun.co/ --head
HTTP/2 200
accept-ranges: bytes
alt-svc: h3=":443"; ma=2592000
cache-control: public, max-age=60, must-revalidate
cache-status: Souin; fwd=uri-miss; detail=UPSTREAM-ERROR-OR-EMPTY-RESPONSE; key=HEAD-https-ysun.co-/
content-type: text/html; charset=utf-8
strict-transport-security: max-age=31536000; includeSubDomains; preload
vary: Accept-Encoding
x-content-type-options: nosniff
x-served-by: butte.as10779.net
x-xss-protection: 1; mode=block
content-length: 12814
date: Wed, 06 Aug 2025 11:17:37 GMT

stepbrobd avatar Aug 06 '25 11:08 stepbrobd

My immediate thought on this is adding a check here

https://github.com/darkweak/souin/blob/ced31c1f541928d4f6b93c4e861a8ed1235b67a6/pkg/middleware/middleware.go#L353

To also cache head requests, something like:

if err == nil && (bLen > 0 || rq.Method == "HEAD" || canStatusCodeEmptyContent(statusCode) || s.hasAllowedAdditionalStatusCodesToCache(statusCode)) {

But I didn't check too deeply on whether bLen is larger than 0 or not for HEAD requests, and whether to allow caching HEAD requests depends on allowed_http_verbs

stepbrobd avatar Aug 06 '25 11:08 stepbrobd