Incomplete read error when closing connection

[thmzlt]

I'm getting the following traceback when stopping my connection:

Traceback (most recent call last):
  File "/nix/store/p8j6zgmwlr25cf4viyyqfalfnd9dh9y1-python3-3.7.2-env/lib/python3.7/site-packages/aiormq/connection.py", line 334, in __reader
    weight, channel, frame = await self.__receive_frame()
  File "/nix/store/p8j6zgmwlr25cf4viyyqfalfnd9dh9y1-python3-3.7.2-env/lib/python3.7/site-packages/aiormq/base.py", line 171, in wrap
    return await self.create_task(func(self, *args, **kwargs))
  File "/nix/store/p8j6zgmwlr25cf4viyyqfalfnd9dh9y1-python3-3.7.2-env/lib/python3.7/site-packages/aiormq/base.py", line 25, in __inner
    return await self.task
  File "/nix/store/p8j6zgmwlr25cf4viyyqfalfnd9dh9y1-python3-3.7.2-env/lib/python3.7/site-packages/aiormq/connection.py", line 285, in __receive_frame
    frame_header = await self.reader.readexactly(1)
  File "/nix/store/p8j6zgmwlr25cf4viyyqfalfnd9dh9y1-python3-3.7.2-env/lib/python3.7/asyncio/streams.py", line 677, in readexactly
    raise IncompleteReadError(incomplete, n)
asyncio.streams.IncompleteReadError: 0 bytes read on a total of 1 expected bytes

I'm pretty much calling channel.close() and then connection.close() before stopping and closing the loop. Shouldn't it close without an error?

[thmzlt]

That is aiormq 2.4 but I get the same traceback on 2.5.

[decaz]

I use aio-pika's robust connection and I've got the same error when restarting RabbitMQ server. @mosquito I guess this is normal, isn't it?

[mosquito]

Yes! It's normal in case TCP connection problems. This exception means unexpected connection close while reading frame header.

[decaz]

Thanks. I guess it can be closed.

[talwrii]

So calling connection.close() will produce error messages on DEBUG when nothing unexpected has happened.

Here is a repro that causes this error message.

repro.py

import asyncio
import aio_pika

import logging

logging.basicConfig(level=logging.DEBUG)


async def repro():
    while True:
        try:
            connection = await aio_pika.connect("amqp://guest:guest@rabbitmq/")
        except Exception:
            await asyncio.sleep(1)
        else:
            break

    channel = await connection.channel()
    queue = await channel.declare_queue("queue")
    await queue.consume(lambda *_: None)
    await channel.default_exchange.publish(
        aio_pika.Message(body="hello".encode("utf8")), routing_key="queue"
    )
    await connection.close()


asyncio.get_event_loop().run_until_complete(repro())

Dockerfile

FROM python

ENV PYTHONASYNCIODEBUG true
RUN pip3 install aio-pika

docker-compose.yml

version: '3.6'
services:
  rabbitmq:
    image: "rabbitmq"
  repro:
    build: .
    command: "python3 /app/repro.py"
    volumes:
      - ".:/app"

networks:
  default:
    name: rabbit

This produces the following error:

repro_1     | DEBUG:aiormq.connection:Can not read bytes from server:
repro_1     | Traceback (most recent call last):
repro_1     |   File "/usr/local/lib/python3.8/site-packages/aiormq/connection.py", line 374, in __reader
repro_1     |     weight, channel, frame = await self.__receive_frame()
repro_1     |   File "/usr/local/lib/python3.8/site-packages/aiormq/connection.py", line 326, in __receive_frame
repro_1     |     frame_header = await self.reader.readexactly(1)
repro_1     |   File "/usr/local/lib/python3.8/asyncio/streams.py", line 721, in readexactly
repro_1     |     raise exceptions.IncompleteReadError(incomplete, n)
repro_1     | asyncio.exceptions.IncompleteReadError: 0 bytes read on a total of 1 expected bytes
repro_1     | DEBUG:aio_pika.connection:Closing AMQP connection None

(As well as some other asyncio related warnings).

[talwrii]

Here is a branch that fixes all these warnings.

[sepetnit]

@talwrii, did you intend to create a branch that fixes this? I also see these warnings in my code and wondering if the correct solution is to avoid them instead of ignoring them.

[talwrii]

@sepetnit Whoops. Yep, think I got distracted here's a pull request: #86

Not sure this is a nice approach, I set a flag when shutdown beings and then don't print this message (this is not "ignoring" the problem as such - that error messages means tha the connection has closed so it's expected behaviour)

There were aslo some bugs during shutdown that this branch fixes.