Enabling cache increases response times

[crummy]

I have a Caddyfile like this:

{
    order cache before rewrite
    cache
}

ourdomain {
    encode gzip
    root * /home/ubuntu/landing
    try_files {path} {path}/index.html

    @fileExists file
    handle @fileExists {
        file_server
    }

    handle {
        cache
        reverse_proxy http://remoteserver:4567 {
            lb_try_duration 60s
            fail_duration 1s
            health_uri /health
            health_interval 1s
        }
    }
    log {
        output file /var/log/caddy/access.log
        format console
    }
}

When I request a file from it, using this command:

curl -o /dev/null -s -w 'Establish Connection: %{time_connect}s\nTTFB: %{time_starttransfer}s\nTotal: %{time_total}s\n'  https://ourdomain/file.js

I get a response like this:

Establish Connection: 0.182702s
TTFB: 2.137184s
Total: 3.592550s

If I remove the cache line from the handle block, I see a response like this:

Establish Connection: 0.304530s
TTFB: 0.960026s
Total: 2.472493s

Consistently, enabling the cache seems to make my requests take longer. Is this because the cache is downloading the entire file from upstream, before serving it to the client? As opposed to just streaming the entire thing immediately?

Is there a way to avoid this behaviour?

(This applies to both my first request and subsequent requests but I'm guessing that's because my max-age=0... still working on that)

[darkweak]

Hello @crummy sorry for the delay. The max-age=0 in the Cache-Control header force the revalidation. The new version I'm working on should decrease the response time, you can preview that version using xcaddy build --with github.com/darkweak/souin/plugins/caddy@ bbb3ba92593cfad8fa9d1bf6ec69e992b960dd52 --with github.com/darkweak/souin@ bbb3ba92593cfad8fa9d1bf6ec69e992b960dd52

[crummy]

I ran xcaddy build --with github.com/darkweak/souin/plugins/caddy@bbb3ba92593cfad8fa9d1bf6ec69e992b960dd52 --with github.com/darkweak/souin@bbb3ba92593cfad8fa9d1bf6ec69e992b960dd52 then copied over the binary and reloaded. When I did so I received this output:

> sudo caddy reload
2023/03/01 18:49:29.917 INFO    using adjacent Caddyfile
2023/03/01 18:49:29.920 WARN    Caddyfile input is not formatted; run the 'caddy fmt' command to fix inconsistencies    {"adapter": "caddyfile", "file": "Caddyfile", "line": 2}
Error: sending configuration to instance: caddy responded with error: HTTP 400: {"error":"loading config: loading new config: loading cache app module: decoding module config: cache: json: unknown field \"Storer\""}

Reverting the cache-specific lines gets Caddy working again.

[darkweak]

I missed the json configuration validation. I'll fix that in the next release and add some tests to ensure everything can reload without any issues. Sorry for that.

[crummy]

Thanks, I'd be happy to test again when the fix is in.

[darkweak]

I tried with your configuration on the latest release (just use xcaddy build --with github.com/darkweak/souin/plugins/caddy with the Caddyfile you given on top of this issue and it worked without any issues. Anyway I will find some time to write test cases about the configuration reload.

[darkweak]

Can you try with xcaddy build --with github.com/darkweak/souin@f05fcc6808b9ba8cc61833b329b0b2b4697a2ad7 --with github.com/darkweak/souin/plugins/caddy@f05fcc6808b9ba8cc61833b329b0b2b4697a2ad7 @crummy?

[crummy]

That build is lots faster on the initial request, seems similar to with caching disabled. Thanks so much. I'll figure out my max-age header issue now and should be good!