Skip to content

[Bug] Aioredis cancellation of blocking operations stucks next operations #2579

Description

@merunes-goldman

Version: redis-py 4.4.2, redis 7.0.8-1

Platform: Python 3.9.16 on Arch Linux

Description: Aioredis cancellation of blocking operations, like blpop, does not work correctly. Operation seems cancelled, but any next operation, like rpush will stuck, key does not matter. If there is timeout - stuck will last as long as time is out, otherwise forever.

Example

import asyncio
import time
from typing import Awaitable, List, TypeVar, cast

from redis import asyncio as aioredis

_T = TypeVar('_T')


async def _task_1(redis: aioredis.Redis) -> str:
    async with redis as r:
        await cast(Awaitable[List[str]], r.blpop('key_1', timeout=10))

    return 'task_1_completed'


async def _task_2() -> str:
    await asyncio.sleep(1)

    return 'task_2_completed'


async def _first_completed(*tasks: Awaitable[_T]) -> _T:
    done, pending = await asyncio.wait(
        [asyncio.ensure_future(task) for task in tasks], return_when=asyncio.FIRST_COMPLETED
    )

    for task in pending:
        task.cancel()

    await asyncio.wait(pending)

    print(done)
    print(pending)

    return done.pop().result()


async def _redis_rpush(redis: aioredis.Redis) -> None:
    async with redis as r:
        await cast(Awaitable[int], r.rpush('key_2', ''))


async def _main() -> None:
    redis = aioredis.from_url('redis://localhost/3', encoding='utf-8', decode_responses=True)

    print(await _first_completed(_task_1(redis), _task_2()))

    rpush_start_time = time.time()
    await _redis_rpush(redis)
    rpush_end_time = time.time()

    print(f"rpush seconds: {rpush_end_time - rpush_start_time}")

    await cast(Awaitable[bool], redis.flushdb())


if __name__ == '__main__':
    asyncio.run(_main())

Output

{<Task finished name='Task-3' coro=<_task_2() done, defined at /home/merunes/vhome/proj/work/robohood-roboapi/robohood_roboapi/main.py:17> result='task_2_completed'>}
{<Task cancelled name='Task-2' coro=<_task_1() done, defined at /home/merunes/vhome/proj/work/robohood-roboapi/robohood_roboapi/main.py:10>>}
task_2_completed
rpush seconds: 9.014980554580688

rpush seconds are weird, it seems like internally blpop wasn't cancelled and rpush is waiting it to complete.

PS:
Maybe connected with:

#2028
#2551
#2523

Metadata

Metadata

Assignees

No one assigned

    Labels

    No labels
    No labels

    Type

    No type

    Fields

    No fields configured for issues without a type.

    Projects

    No projects

    Milestone

    No milestone

    Relationships

    None yet

    Development

    No branches or pull requests

    Issue actions