early_ttl not working in combination with CacheEtagMiddleware

[rueschm]

early_ttl works as expected

e.g. when used like @cache.early(ttl="5m", early_ttl="1m") i see the refresh which is called in the background after 1 minute.

if I add the CacheEtagMiddleware the refresh after early_ttl (1m) does not happen anymore but only the ttl refresh after 5 minute works.

Using Version 7.0.0

[Krukov]

Hi , thanks for notifying but I couldn't reproduce this issue. It will be grateful if you will provide a piece of code to reproduce it

[rueschm]

Hi, thanks for your response, here a minimal code sample:

import datetime

from cashews import cache
from cashews.contrib.fastapi import CacheEtagMiddleware
from fastapi import FastAPI

app = FastAPI()

@app.on_event("startup")
async def startup_event():
    cache.setup("mem://")

app.add_middleware(CacheEtagMiddleware)

@app.get("/test")
@cache.early(ttl="5m", early_ttl="1m")
async def test():
    print(datetime.datetime.now()," refresh")
    return {"hello": "world"}

I start the application and then make a request every minute to http://localhost:8000/test. The logs are:

INFO:     Started server process [77581]
INFO:     Waiting for application startup.
INFO:     Application startup complete.
2024-02-14 15:00:27.698238  refresh
INFO:     127.0.0.1:50270 - "GET /test HTTP/1.1" 200 OK
INFO:     127.0.0.1:50289 - "GET /test HTTP/1.1" 304 Not Modified
INFO:     127.0.0.1:50291 - "GET /test HTTP/1.1" 304 Not Modified
INFO:     127.0.0.1:50298 - "GET /test HTTP/1.1" 304 Not Modified
INFO:     127.0.0.1:50300 - "GET /test HTTP/1.1" 304 Not Modified
2024-02-14 15:05:38.306540  refresh
INFO:     127.0.0.1:50315 - "GET /test HTTP/1.1" 200 OK

As you can see in the logs the first time the function is executed again not taken from the cache is after 5 minutes. In my understanding this should happen after 1 minute already. I am also not completely sure why the response code after the 5 minute and the refresh i then 200. As the result is still the same it could be 304 as well.

If I remove the line

app.add_middleware(CacheEtagMiddleware)

the logs are:

INFO:     Started server process [77980]
INFO:     Waiting for application startup.
INFO:     Application startup complete.
2024-02-14 15:07:01.202219  refresh
INFO:     127.0.0.1:50327 - "GET /test HTTP/1.1" 200 OK
INFO:     127.0.0.1:50329 - "GET /test HTTP/1.1" 200 OK
2024-02-14 15:08:30.271739  refresh
INFO:     127.0.0.1:50339 - "GET /test HTTP/1.1" 200 OK

now the first refresh happens already after 1 minute. That is the behaviour I would expect.

Pip freeze:

annotated-types==0.6.0
anyio==4.2.0
cashews==7.0.0
click==8.1.7
fastapi==0.109.2
h11==0.14.0
idna==3.6
pydantic==2.6.1
pydantic_core==2.16.2
sniffio==1.3.0
starlette==0.36.3
typing_extensions==4.9.0
uvicorn==0.27.1

[Krukov]

Oh got you, catch it, that is because of logic with etag (You requests have a Etag header and we just check that we have this etag in a cache). I will try to fix it somehow asap

[Krukov]

not released yet

[Krukov]

Fixed with 7.1.0 version. Feel free to reopen the issue if it still exist