Formatter Called with Formatted Value

[robert-schmidtke]

Hi, first of all thanks for providing cashews! I recently started using it and noticed that, when using custom formatters in tags, they get called with the already formatted value for matching, see the below example for reproducing this behavior.

Is this expected and should I work around this (e.g. check if the formatter is called with a string already), or is this an actual issue?

import asyncio
from collections.abc import Mapping
from typing import Any

from cashews import cache, default_formatter

cache.setup("mem://?size=1000000&check_interval=5")

@default_formatter.register("get_item", preformat=False)
def _getitem_func(mapping: Mapping[str, Any], key: str) -> str:
    try:
        return str(mapping[key])
    except Exception as e:
        # when key/tag matching, this may be called with the rendered value
        raise RuntimeError(f"{mapping=}, {key=}") from e

@cache(
    ttl="1h",
    key="keys:{mapping:get_item(bar)}",
    tags=["tags:{mapping:get_item(bar)}"],
)
async def foo(mapping: str) -> None:
    print("Foo: ", mapping)

async def main() -> None:
    await foo({"bar": "baz"})

if __name__ == "__main__":
    asyncio.run(main())

# prints: Foo:  {'bar': 'baz'}
Traceback (most recent call last):
  File "/home/rschmidtke/scratch/testtags.py", line 13, in _getitem_func
    return str(mapping[key])
TypeError: string indices must be integers

The above exception was the direct cause of the following exception:

Traceback (most recent call last):
  File "/home/rschmidtke/scratch/testtags.py", line 33, in <module>
    asyncio.run(main())
  File "/home/rschmidtke/miniforge3/envs/myenv/lib/python3.10/asyncio/runners.py", line 44, in run
    return loop.run_until_complete(main)
  File "/home/rschmidtke/miniforge3/envs/myenv/lib/python3.10/asyncio/base_events.py", line 649, in run_until_complete
    return future.result()
  File "/home/rschmidtke/scratch/testtags.py", line 29, in main
    await foo({"bar": "baz"})
  File "/home/rschmidtke/miniforge3/envs/myenv/lib/python3.10/site-packages/cashews/wrapper/decorators.py", line 69, in _call
    return await thunder_protection(decorator)(*args, **kwargs)
  File "/home/rschmidtke/miniforge3/envs/myenv/lib/python3.10/site-packages/cashews/decorators/locked.py", line 102, in _wrapper
    return await task
  File "/home/rschmidtke/miniforge3/envs/myenv/lib/python3.10/site-packages/cashews/decorators/cache/simple.py", line 65, in _wrap
    await backend.set(_cache_key, result, expire=_ttl, tags=_tags)
  File "/home/rschmidtke/miniforge3/envs/myenv/lib/python3.10/site-packages/cashews/wrapper/tags.py", line 119, in set
    self._tags_registry.check_tags_registered(key, tags)
  File "/home/rschmidtke/miniforge3/envs/myenv/lib/python3.10/site-packages/cashews/wrapper/tags.py", line 41, in check_tags_registered
    key_tags = set(self.get_key_tags(key))
  File "/home/rschmidtke/miniforge3/envs/myenv/lib/python3.10/site-packages/cashews/wrapper/tags.py", line 27, in get_key_tags
    tag = default_format(tag, **group_dict)
  File "/home/rschmidtke/miniforge3/envs/myenv/lib/python3.10/site-packages/cashews/formatter.py", line 163, in default_format
    return default_formatter.format(template, **_template_context)
  File "/home/rschmidtke/miniforge3/envs/myenv/lib/python3.10/string.py", line 161, in format
    return self.vformat(format_string, args, kwargs)
  File "/home/rschmidtke/miniforge3/envs/myenv/lib/python3.10/string.py", line 165, in vformat
    result, _ = self._vformat(format_string, args, kwargs, used_args, 2)
  File "/home/rschmidtke/miniforge3/envs/myenv/lib/python3.10/string.py", line 218, in _vformat
    result.append(self.format_field(obj, format_spec))
  File "/home/rschmidtke/miniforge3/envs/myenv/lib/python3.10/site-packages/cashews/formatter.py", line 118, in format_field
    return func(value, *args)
  File "/home/rschmidtke/scratch/testtags.py", line 16, in _getitem_func
    raise RuntimeError(f"{mapping=}, {key=}") from e
RuntimeError: mapping='baz', key='bar'

[Krukov]

Hello @robert-schmidtke!

This is definitely a bug or problem in the design of the tagging system. I don't know how to fix it quickly. Probably I need to remove check_tags_registered

For now I can suggest to fix it with some kind of crutch

@default_formatter.register("get_item", preformat=False)
def _getitem_func(mapping: Mapping[str, Any], key: str) -> str:
    if not isinstance(mapping, dict):
         return mapping
    return mapping[key]

[robert-schmidtke]

Yeah that's almost exactly how I worked around that for now, so not a blocker at this time.

I believe there was a similar issue with tags when configuring a prefix during setup, but I'm not on my machine right now to reproduce.

[Krukov]

thanks, I think that I understand a problem It will be grateful if you will share an example when you will have a time

[robert-schmidtke]

Hi, came up with a small example below for the tags too.

import asyncio

from cashews import cache

cache.setup("mem://", prefix="testing")

# the below works
# cache.setup("mem://")

@cache(
    ttl="1h",
    key="testing:key",
    tags=["tag"],  # using "testing:tag" here would also fail
)
async def cached(param: str):
    print(param)

async def main():
    await cached("TESTME")
    await cached("TESTME")

if __name__ == "__main__":
    asyncio.run(main())

# prints TESTME
Traceback (most recent call last):
  File "/home/rschmidtke/workspace/scratch/tags.py", line 26, in <module>
    asyncio.run(main())
  File "/home/rschmidtke/miniforge3/envs/testenv/lib/python3.10/asyncio/runners.py", line 44, in run
    return loop.run_until_complete(main)
  File "/home/rschmidtke/miniforge3/envs/testenv/lib/python3.10/asyncio/base_events.py", line 649, in run_until_complete
    return future.result()
  File "/home/rschmidtke/workspace/scratch/tags.py", line 21, in main
    await cached("TESTME")
  File "/home/rschmidtke/miniforge3/envs/testenv/lib/python3.10/site-packages/cashews/wrapper/decorators.py", line 69, in _call
    return await thunder_protection(decorator)(*args, **kwargs)
  File "/home/rschmidtke/miniforge3/envs/testenv/lib/python3.10/site-packages/cashews/decorators/locked.py", line 102, in _wrapper
    return await task
  File "/home/rschmidtke/miniforge3/envs/testenv/lib/python3.10/site-packages/cashews/decorators/cache/simple.py", line 65, in _wrap
    await backend.set(_cache_key, result, expire=_ttl, tags=_tags)
  File "/home/rschmidtke/miniforge3/envs/testenv/lib/python3.10/site-packages/cashews/wrapper/tags.py", line 121, in set
    await self.set_add(self._tags_key_prefix + tag, key, expire=expire)
  File "/home/rschmidtke/miniforge3/envs/testenv/lib/python3.10/site-packages/cashews/wrapper/commands.py", line 178, in set_add
    return await self._with_middlewares(Command.SET_ADD, key)(key, *values, expire=ttl_to_seconds(expire))
  File "/home/rschmidtke/miniforge3/envs/testenv/lib/python3.10/site-packages/cashews/wrapper/wrapper.py", line 45, in _with_middlewares
    backend, middlewares = self._get_backend_and_config(key)
  File "/home/rschmidtke/miniforge3/envs/testenv/lib/python3.10/site-packages/cashews/wrapper/transaction.py", line 36, in _get_backend_and_config
    backend, config = super()._get_backend_and_config(key)
  File "/home/rschmidtke/miniforge3/envs/testenv/lib/python3.10/site-packages/cashews/wrapper/wrapper.py", line 38, in _get_backend_and_config
    raise NotConfiguredError("Backend for given key not configured")
cashews.exceptions.NotConfiguredError: Backend for given key not configured

[Krukov]

Fixed with 7.1.0 version. I removed check_tags_registered - it should fix the first issue.

Regarding prefix - I added note to the Readme (documentation) that tags require to setup a default cache or a tag backend

[robert-schmidtke]

Hi, this issue still seems to exist with cache invalidation.

import asyncio
from collections.abc import Mapping
from typing import Any

from cashews import cache, default_formatter

cache.setup("mem://?size=1000000&check_interval=5")

@default_formatter.register("get_item", preformat=False)
def _getitem_func(mapping: Mapping[str, Any], key: str) -> str:
    try:
        return str(mapping[key])
    except Exception as e:
        # when key/tag matching, this may be called with the rendered value
        raise RuntimeError(f"{mapping=}, {key=}") from e

@cache(
    ttl="1h",
    key="prefix:keys:{mapping:get_item(bar)}",
    tags=["prefix:tags:{mapping:get_item(bar)}"],
)
async def foo(mapping: str) -> None:
    print("Foo", mapping)

@cache.invalidate("prefix:keys:{mapping:get_item(bar)}")
async def bar(mapping: str) -> None:
    print("Bar", mapping)

async def main() -> None:
    await foo({"bar": "baz"})
    await bar({"bar": "baz"})

if __name__ == "__main__":
    asyncio.run(main())

# prints Foo {'bar': 'baz'}
# prints Bar {'bar': 'baz'}
Traceback (most recent call last):
  File "/home/rschmidtke/workspace/scratch/cashewstest.py", line 13, in _getitem_func
    return str(mapping[key])
TypeError: string indices must be integers

The above exception was the direct cause of the following exception:

Traceback (most recent call last):
  File "/home/rschmidtke/workspace/scratch/cashewstest.py", line 38, in <module>
    asyncio.run(main())
  File "/home/rschmidtke/miniforge3/envs/testenv/lib/python3.9/asyncio/runners.py", line 44, in run
    return loop.run_until_complete(main)
  File "/home/rschmidtke/miniforge3/envs/testenv/lib/python3.9/asyncio/base_events.py", line 647, in run_until_complete
    return future.result()
  File "/home/rschmidtke/workspace/scratch/cashewstest.py", line 34, in main
    await bar({"bar": "baz"})
  File "/home/rschmidtke/miniforge3/envs/testenv/lib/python3.9/site-packages/cashews/validation.py", line 32, in _wrap
    await backend.delete_match(key)
  File "/home/rschmidtke/miniforge3/envs/testenv/lib/python3.9/site-packages/cashews/wrapper/commands.py", line 132, in delete_match
    return await self._with_middlewares(Command.DELETE_MATCH, pattern)(pattern=pattern)
  File "/home/rschmidtke/miniforge3/envs/testenv/lib/python3.9/site-packages/cashews/wrapper/disable_control.py", line 20, in _is_disable_middleware
    return await call(*args, **kwargs)
  File "/home/rschmidtke/miniforge3/envs/testenv/lib/python3.9/site-packages/cashews/wrapper/callback.py", line 20, in __call__
    result = await call(*args, **kwargs)
  File "/home/rschmidtke/miniforge3/envs/testenv/lib/python3.9/site-packages/cashews/validation.py", line 69, in _invalidate_middleware
    return await call(*args, **kwargs)
  File "/home/rschmidtke/miniforge3/envs/testenv/lib/python3.9/site-packages/cashews/wrapper/auto_init.py", line 15, in _auto_init
    return await call(*args, **kwargs)
  File "/home/rschmidtke/miniforge3/envs/testenv/lib/python3.9/site-packages/cashews/backends/memory.py", line 134, in delete_match
    await self._delete(key)
  File "/home/rschmidtke/miniforge3/envs/testenv/lib/python3.9/site-packages/cashews/backends/memory.py", line 124, in _delete
    await self._call_on_remove_callbacks(key)
  File "/home/rschmidtke/miniforge3/envs/testenv/lib/python3.9/site-packages/cashews/backends/interface.py", line 227, in _call_on_remove_callbacks
    await callback(keys, backend=self)
  File "/home/rschmidtke/miniforge3/envs/testenv/lib/python3.9/site-packages/cashews/wrapper/tags.py", line 71, in _callback
    for tag, _keys in self._group_by_tags(keys).items():
  File "/home/rschmidtke/miniforge3/envs/testenv/lib/python3.9/site-packages/cashews/wrapper/tags.py", line 79, in _group_by_tags
    for tag in self.get_key_tags(key):
  File "/home/rschmidtke/miniforge3/envs/testenv/lib/python3.9/site-packages/cashews/wrapper/tags.py", line 84, in get_key_tags
    return self._tags_registry.get_key_tags(key)
  File "/home/rschmidtke/miniforge3/envs/testenv/lib/python3.9/site-packages/cashews/wrapper/tags.py", line 26, in get_key_tags
    tag = default_format(tag, **group_dict)
  File "/home/rschmidtke/miniforge3/envs/testenv/lib/python3.9/site-packages/cashews/formatter.py", line 163, in default_format
    return default_formatter.format(template, **_template_context)
  File "/home/rschmidtke/miniforge3/envs/testenv/lib/python3.9/string.py", line 161, in format
    return self.vformat(format_string, args, kwargs)
  File "/home/rschmidtke/miniforge3/envs/testenv/lib/python3.9/string.py", line 165, in vformat
    result, _ = self._vformat(format_string, args, kwargs, used_args, 2)
  File "/home/rschmidtke/miniforge3/envs/testenv/lib/python3.9/string.py", line 218, in _vformat
    result.append(self.format_field(obj, format_spec))
  File "/home/rschmidtke/miniforge3/envs/testenv/lib/python3.9/site-packages/cashews/formatter.py", line 118, in format_field
    return func(value, *args)
  File "/home/rschmidtke/workspace/scratch/cashewstest.py", line 16, in _getitem_func
    raise RuntimeError(f"{mapping=}, {key=}") from e
RuntimeError: mapping='baz', key='bar'

[Krukov]

Was fixed in 7.2.0 ( I hope )

feel free to reopen

[robert-schmidtke]

Both the first (https://github.com/Krukov/cashews/issues/214#issue-2256766108) and third (https://github.com/Krukov/cashews/issues/214#issuecomment-2108096389) tests succeed now.

However the second (https://github.com/Krukov/cashews/issues/214#issuecomment-2096049065) still fails. I'm not 100% sure this is expected behavior when using both the prefix option as well as the actual prefix in the key.

Unfortunately, the issue still appears to be there when deleting tags, see the below snippet.

import asyncio
from collections.abc import Mapping
from typing import Any

from cashews import cache, default_formatter

cache.setup("mem://?size=1000000&check_interval=5")

@default_formatter.register("get_item", preformat=False)
def _getitem_func(mapping: Mapping[str, Any], key: str) -> str:
    try:
        return str(mapping[key])
    except Exception as e:
        # when key/tag matching, this may be called with the rendered value
        raise RuntimeError(f"{mapping=}, {key=}") from e

@cache(
    ttl="1h",
    key="prefix:keys:{mapping:get_item(bar)}",
    tags=["prefix:tags:{mapping:get_item(bar)}"],
)
async def foo(mapping: str) -> None:
    print("Foo", mapping)

async def main() -> None:
    await foo({"bar": "baz"})
    await cache.delete_tags("prefix:tags:baz")

if __name__ == "__main__":
    asyncio.run(main())

# prints Foo {'bar': 'baz'}
Traceback (most recent call last):
  File "/home/rschmidtke/workspace/other/cashews/formatter_test.py", line 13, in _getitem_func
    return str(mapping[key])
TypeError: string indices must be integers

The above exception was the direct cause of the following exception:

Traceback (most recent call last):
  File "/home/rschmidtke/workspace/other/cashews/formatter_test.py", line 34, in <module>
    asyncio.run(main())
  File "/home/rschmidtke/miniforge3/envs/cashews/lib/python3.10/asyncio/runners.py", line 44, in run
    return loop.run_until_complete(main)
  File "/home/rschmidtke/miniforge3/envs/cashews/lib/python3.10/asyncio/base_events.py", line 649, in run_until_complete
    return future.result()
  File "/home/rschmidtke/workspace/other/cashews/formatter_test.py", line 30, in main
    await cache.delete_tags(f"prefix:tags:baz")
  File "/home/rschmidtke/workspace/other/cashews/cashews/wrapper/tags.py", line 88, in delete_tags
    await self._delete_tag(tag)
  File "/home/rschmidtke/workspace/other/cashews/cashews/wrapper/tags.py", line 96, in _delete_tag
    await self.delete_many(*keys)
  File "/home/rschmidtke/workspace/other/cashews/cashews/wrapper/commands.py", line 148, in delete_many
    await self._with_middlewares(Command.DELETE_MANY, _keys[0])(*_keys)
  File "/home/rschmidtke/workspace/other/cashews/cashews/wrapper/disable_control.py", line 21, in _is_disable_middleware
    return await call(*args, **kwargs)
  File "/home/rschmidtke/workspace/other/cashews/cashews/wrapper/callback.py", line 20, in __call__
    result = await call(*args, **kwargs)
  File "/home/rschmidtke/workspace/other/cashews/cashews/validation.py", line 71, in _invalidate_middleware
    return await call(*args, **kwargs)
  File "/home/rschmidtke/workspace/other/cashews/cashews/wrapper/auto_init.py", line 13, in _auto_init
    return await call(*args, **kwargs)
  File "/home/rschmidtke/workspace/other/cashews/cashews/backends/memory.py", line 130, in delete_many
    await self._delete(key)
  File "/home/rschmidtke/workspace/other/cashews/cashews/backends/memory.py", line 124, in _delete
    await self._call_on_remove_callbacks(key)
  File "/home/rschmidtke/workspace/other/cashews/cashews/backends/interface.py", line 227, in _call_on_remove_callbacks
    await callback(keys, backend=self)
  File "/home/rschmidtke/workspace/other/cashews/cashews/wrapper/tags.py", line 71, in _callback
    for tag, _keys in self._group_by_tags(keys).items():
  File "/home/rschmidtke/workspace/other/cashews/cashews/wrapper/tags.py", line 79, in _group_by_tags
    for tag in self.get_key_tags(key):
  File "/home/rschmidtke/workspace/other/cashews/cashews/wrapper/tags.py", line 84, in get_key_tags
    return self._tags_registry.get_key_tags(key)
  File "/home/rschmidtke/workspace/other/cashews/cashews/wrapper/tags.py", line 26, in get_key_tags
    tag = default_format(tag, **group_dict)
  File "/home/rschmidtke/workspace/other/cashews/cashews/formatter.py", line 166, in default_format
    return default_formatter.format(template, **_template_context)
  File "/home/rschmidtke/miniforge3/envs/cashews/lib/python3.10/string.py", line 161, in format
    return self.vformat(format_string, args, kwargs)
  File "/home/rschmidtke/miniforge3/envs/cashews/lib/python3.10/string.py", line 165, in vformat
    result, _ = self._vformat(format_string, args, kwargs, used_args, 2)
  File "/home/rschmidtke/miniforge3/envs/cashews/lib/python3.10/string.py", line 218, in _vformat
    result.append(self.format_field(obj, format_spec))
  File "/home/rschmidtke/workspace/other/cashews/cashews/formatter.py", line 118, in format_field
    return func(value, *args)
  File "/home/rschmidtke/workspace/other/cashews/formatter_test.py", line 16, in _getitem_func
    raise RuntimeError(f"{mapping=}, {key=}") from e
RuntimeError: mapping='baz', key='bar'

[Krukov]

It seems that some of the internal logic for working with tags is broken and not very flexible. I can give details, but in short, I'm going to rework it a little in the part that manages the lifetime of the key "in the tag". Give me a time. I will let you know when I fix it