caddyserver / cache-handler

Distributed HTTP caching module for Caddy
Apache License 2.0
235 stars 17 forks source link

fwd=uri-miss #48

Closed frederichoule closed 1 year ago

frederichoule commented 1 year ago

I keep getting fwd=uri-miss on all requests, on all URLs.

cache-status: TestCache; fwd=uri-miss; stored; key=GET-https-temporary-rul

I tried adding request_header -Cache-Control in case it was the Cache-Control header from the browser, but without success. What am I doing wrong?

Caddyfile looks like that:

{
    order cache before rewrite

    on_demand_tls {
        ask http://localhost:5555/ask
        interval 2m
        burst 5
    }

    cache {
        allowed_http_verbs GET
        ttl 86400s
        redis {
            url 127.0.0.1:6379
        }
        key {
            disable_body
            disable_query
        }
    }
}

(upstream) {
    method GET

    request_header -Cache-Control

    header * {
        Server LPV2
        -X-Cloud-Trace-Context
        defer
    }

    tls email@email.com {
        on_demand
    }

    reverse_proxy endpoint.com {
        header_up Host {upstream_hostport}
    }

    cache
}

localhost {
    tls internal
    import upstream
}

https:// {
    import upstream
}

http:// {
    redir https://{host}{uri} permanent
}
darkweak commented 1 year ago

Can you post the incoming request logs?

frederichoule commented 1 year ago

Ok so I recreated a simple server.

Caddyfile:

{
    order cache before rewrite

    log {
        level debug
    }

    on_demand_tls {
        ask http://localhost:5555/ask
        interval 2m
        burst 5
    }

    cache {
        allowed_http_verbs GET
        ttl 86400s
        redis {
            url 127.0.0.1:6379
        }
        key {
            disable_body
            disable_query
        }
    }
}

(upstream) {
    method GET

    tls test@test.com {
        on_demand
    }

    reverse_proxy postman-echo.com {
        header_up Host {upstream_hostport}
    }

    cache
}

localhost {
    tls internal
    import upstream
}

https:// {
    import upstream
}

http:// {
    redir https://{host}{uri} permanent
}

First request:

2023/03/16 17:12:20.593 DEBUG   http.handlers.cache Incoming request: &{Method:GET URL:/get Proto:HTTP/2.0 ProtoMajor:2 ProtoMinor:0 Header:map[Accept:[text/html,application/xhtml+xml,application/xml;q=0.9,image/avif,image/webp,image/apng,*/*;q=0.8,application/signed-exchange;v=b3;q=0.7] Accept-Encoding:[gzip, deflate, br] Accept-Language:[en-CA,en;q=0.9] Cache-Control:[max-age=0] Cookie:[sails.sid=s%3Ar_benUdJEuY5PMhSglgXUl_cOj-RyRUV.8GvPxL3s05Y3qSpgDdeNPbJ8Sbo2CStn%2FrjnTWnUL7E] Date:[Thu, 16 Mar 2023 17:12:20 UTC] Sec-Ch-Ua:["Google Chrome";v="111", "Not(A:Brand";v="8", "Chromium";v="111"] Sec-Ch-Ua-Mobile:[?0] Sec-Ch-Ua-Platform:["macOS"] Sec-Fetch-Dest:[document] Sec-Fetch-Mode:[navigate] Sec-Fetch-Site:[none] Sec-Fetch-User:[?1] Upgrade-Insecure-Requests:[1] User-Agent:[Mozilla/5.0 (Macintosh; Intel Mac OS X 10_15_7) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/111.0.0.0 Safari/537.36]] Body:{Reader:0x4006c27dd0} GetBody:<nil> ContentLength:0 TransferEncoding:[] Close:false Host:localhost:8043 Form:map[] PostForm:map[] MultipartForm:<nil> Trailer:map[] RemoteAddr:172.17.0.1:58692 RequestURI:/get TLS:0x4000538bb0 Cancel:<nil> Response:<nil> ctx:0x4006c27ef0}

2023/03/16 17:12:20.595 DEBUG   http.handlers.reverse_proxy selected upstream   {"dial": "postman-echo.com:80", "total_upstreams": 1}

2023/03/16 17:12:21.014 DEBUG   http.handlers.reverse_proxy upstream roundtrip  {"upstream": "postman-echo.com:80", "duration": 0.418987167, "request": {"remote_ip": "172.17.0.1", "remote_port": "58692", "proto": "HTTP/2.0", "method": "GET", "host": "postman-echo.com:80", "uri": "/get", "headers": {"User-Agent": ["Mozilla/5.0 (Macintosh; Intel Mac OS X 10_15_7) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/111.0.0.0 Safari/537.36"], "Accept-Encoding": ["gzip, deflate, br"], "X-Forwarded-For": ["172.17.0.1"], "X-Forwarded-Host": ["localhost:8043"], "Accept-Language": ["en-CA,en;q=0.9"], "Sec-Fetch-Site": ["none"], "Sec-Fetch-Dest": ["document"], "Sec-Fetch-User": ["?1"], "Cookie": [], "Accept": ["text/html,application/xhtml+xml,application/xml;q=0.9,image/avif,image/webp,image/apng,*/*;q=0.8,application/signed-exchange;v=b3;q=0.7"], "Upgrade-Insecure-Requests": ["1"], "Sec-Fetch-Mode": ["navigate"], "Date": ["Thu, 16 Mar 2023 17:12:20 UTC"], "Sec-Ch-Ua-Platform": ["\"macOS\""], "Cache-Control": ["max-age=0"], "Sec-Ch-Ua-Mobile": ["?0"], "Sec-Ch-Ua": ["\"Google Chrome\";v=\"111\", \"Not(A:Brand\";v=\"8\", \"Chromium\";v=\"111\""], "X-Forwarded-Proto": ["https"]}, "tls": {"resumed": false, "version": 772, "cipher_suite": 4865, "proto": "h2", "server_name": "localhost"}}, "headers": {"Set-Cookie": [], "Content-Length": ["1175"], "Connection": ["keep-alive"], "Content-Type": ["application/json; charset=utf-8"], "Date": ["Thu, 16 Mar 2023 17:12:21 GMT"], "Etag": ["W/\"497-b1k6AyoZYfWEkhh1YGL2XoPHK6g\""]}, "status": 200}

Second request:

2023/03/16 17:12:25.740 DEBUG   http.handlers.cache Incoming request: &{Method:GET URL:/get Proto:HTTP/2.0 ProtoMajor:2 ProtoMinor:0 Header:map[Accept:[text/html,application/xhtml+xml,application/xml;q=0.9,image/avif,image/webp,image/apng,*/*;q=0.8,application/signed-exchange;v=b3;q=0.7] Accept-Encoding:[gzip, deflate, br] Accept-Language:[en-CA,en;q=0.9] Cache-Control:[max-age=0] Cookie:[sails.sid=s%3AOFpRlD-w1GS8ULER6CNhPgWZRnUwWslP.pGu7WXeSiMbGV8m9fYXlLd9JOwEfmm07yG6da0lxvIk] Date:[Thu, 16 Mar 2023 17:12:25 UTC] Sec-Ch-Ua:["Google Chrome";v="111", "Not(A:Brand";v="8", "Chromium";v="111"] Sec-Ch-Ua-Mobile:[?0] Sec-Ch-Ua-Platform:["macOS"] Sec-Fetch-Dest:[document] Sec-Fetch-Mode:[navigate] Sec-Fetch-Site:[none] Sec-Fetch-User:[?1] Upgrade-Insecure-Requests:[1] User-Agent:[Mozilla/5.0 (Macintosh; Intel Mac OS X 10_15_7) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/111.0.0.0 Safari/537.36]] Body:{Reader:0x40002a5440} GetBody:<nil> ContentLength:0 TransferEncoding:[] Close:false Host:localhost:8043 Form:map[] PostForm:map[] MultipartForm:<nil> Trailer:map[] RemoteAddr:172.17.0.1:58692 RequestURI:/get TLS:0x4000538bb0 Cancel:<nil> Response:<nil> ctx:0x40002a5560}

2023/03/16 17:12:25.742 DEBUG   http.handlers.reverse_proxy selected upstream   {"dial": "postman-echo.com:80", "total_upstreams": 1}

2023/03/16 17:12:25.912 DEBUG   http.handlers.reverse_proxy upstream roundtrip  {"upstream": "postman-echo.com:80", "duration": 0.170712042, "request": {"remote_ip": "172.17.0.1", "remote_port": "58692", "proto": "HTTP/2.0", "method": "GET", "host": "postman-echo.com:80", "uri": "/get", "headers": {"Sec-Ch-Ua-Platform": ["\"macOS\""], "Sec-Fetch-Dest": ["document"], "X-Forwarded-Host": ["localhost:8043"], "Sec-Fetch-Mode": ["navigate"], "X-Forwarded-Proto": ["https"], "Accept": ["text/html,application/xhtml+xml,application/xml;q=0.9,image/avif,image/webp,image/apng,*/*;q=0.8,application/signed-exchange;v=b3;q=0.7"], "Sec-Ch-Ua": ["\"Google Chrome\";v=\"111\", \"Not(A:Brand\";v=\"8\", \"Chromium\";v=\"111\""], "Sec-Fetch-Site": ["none"], "User-Agent": ["Mozilla/5.0 (Macintosh; Intel Mac OS X 10_15_7) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/111.0.0.0 Safari/537.36"], "Accept-Language": ["en-CA,en;q=0.9"], "Date": ["Thu, 16 Mar 2023 17:12:25 UTC"], "Sec-Fetch-User": ["?1"], "Sec-Ch-Ua-Mobile": ["?0"], "Cookie": [], "Cache-Control": ["max-age=0"], "X-Forwarded-For": ["172.17.0.1"], "Accept-Encoding": ["gzip, deflate, br"], "Upgrade-Insecure-Requests": ["1"]}, "tls": {"resumed": false, "version": 772, "cipher_suite": 4865, "proto": "h2", "server_name": "localhost"}}, "headers": {"Set-Cookie": [], "Content-Length": ["1173"], "Connection": ["keep-alive"], "Content-Type": ["application/json; charset=utf-8"], "Date": ["Thu, 16 Mar 2023 17:12:25 GMT"], "Etag": ["W/\"495-jCYMJ1T1/GrfBV8KHHdjkmxWBdc\""]}, "status": 200}

Headers on all requests: cache-status: Souin; fwd=uri-miss; stored

frederichoule commented 1 year ago

At first I thought maybe the Cache-Control header is preventing the cache, so I added:

request_header -Cache-Control
header_down -Cache-Control
header_up -Cache-Control

But still having the same problem

darkweak commented 1 year ago

You have the Cache-Control:[max-age=0] in both requests. That's what Souin is receiving and that's displayed in the logs.

frederichoule commented 1 year ago

That makes sense - but I'm trying to override that by using request_header -Cache-Control, without success. I need it to be cached no matter what the browser is requesting.

francislavoie commented 1 year ago

I think the problem is the directive order: https://caddyserver.com/docs/caddyfile/directives#directive-order

You set the order to cache before rewrite, which means cache is also before request_header. If you want to make request header manipulations before cache, then you can reorder that directive to before cache as well in global options.

frederichoule commented 1 year ago

Ah! That must be it. I'll try that tomorrow morning. Thank you so much guys.

frederichoule commented 1 year ago

Works flawlessly. Thanks.

Suven commented 12 months ago

I'm facing the same issue, but did not completly understand the solution. I tried changing the order-directive to order cache before try_files, which does not seem to be enough.

What would be a minimal example?

{
    order cache before try_files
}

example.net {
    request_header -Cache-Control
    cache
    encode gzip zstd
    reverse_proxy localhost:3000
}