Streamed response truncated on Alpine 3.13/3.14

[dannmartens]

Describe the bug

The stream from the response is truncated, systematically when running on Alpine 3.13/3.14.

The code is developed on Ubuntu 20.04.1 LTS where this issue does not occur.

The read content lengths do not correspond to the actual file sizes.

To Reproduce

All three strategies fail:

1

async for chunk in client_response.content.iter_chunked(config.CHUNK_SIZE):
    yield chunk

2

breaker = 3
while True:
    chunk = await client_response.content.read(config.CHUNK_SIZE)
    print(f'CHUNK path={parsed_url.path} len={len(chunk)}')
    if not chunk:
        # (!) For observation only, logging empty streams (see logs)
        breaker -= 1
        if breaker == 0:
            break
    yield chunk

3

async for chunk, end_of_http_chunk in client_response.content.iter_chunks():
    yield chunk
    if not end_of_http_chunk:
        continue

Expected behavior

Reading the response directly does not truncate:

entity = await client_response.read()

This is the expected behaviour, but this incurs a performance penalty.

Logs/tracebacks

This is the output with the 'breaker' counter from strategy # 2

2021-07-20 06:12:22,157 [DEBUG] proxy - Streaming http://192.168.8.1:3000/static/js/bundle.js
2021-07-20 06:12:22,161 [DEBUG] proxy - Streaming http://192.168.8.1:3000/static/js/vendors~main.chunk.js for None
CHUNK path=/static/js/bundle.js len=7066
CHUNK path=/static/js/bundle.js len=0
CHUNK path=/static/js/bundle.js len=0
CHUNK path=/static/js/bundle.js len=0
CHUNK path=/static/js/vendors~main.chunk.js len=14272
CHUNK path=/static/js/vendors~main.chunk.js len=65536
CHUNK path=/static/js/vendors~main.chunk.js len=2112
CHUNK path=/static/js/vendors~main.chunk.js len=16384
2021-07-20 06:12:22,209 [DEBUG] proxy - Streaming http://192.168.8.1:3000/static/js/main.chunk.js
CHUNK path=/static/js/main.chunk.js len=14273
CHUNK path=/static/js/main.chunk.js len=20841
CHUNK path=/static/js/main.chunk.js len=0
CHUNK path=/static/js/main.chunk.js len=0
CHUNK path=/static/js/main.chunk.js len=0
2021-07-20 06:12:22,300 [DEBUG] proxy - Streaming http://192.168.8.1:3000/manifest.json
2021-07-20 06:12:22,302 [DEBUG] proxy - Streaming http://192.168.8.1:3000/assets/logo.svg
CHUNK path=/manifest.json len=517
CHUNK path=/manifest.json len=0
CHUNK path=/manifest.json len=0
CHUNK path=/manifest.json len=0
CHUNK path=/assets/logo.svg len=906
CHUNK path=/assets/logo.svg len=0
CHUNK path=/assets/logo.svg len=0
CHUNK path=/assets/logo.svg len=0
2021-07-20 06:12:22,326 [DEBUG] proxy - Streaming http://192.168.8.1:3000/logo192.png
CHUNK path=/logo192.png len=4153
CHUNK path=/logo192.png len=0
CHUNK path=/logo192.png len=0
CHUNK path=/logo192.png len=0

Python Version

On Ubuntu 20.04: 3.8.5
On Alpine 3.13: 3.8.11
On Alpine 3.14: 3.9.6

aiohttp Version

Name: aiohttp
Version: 3.7.4.post0
Summary: Async http client/server framework (asyncio)
Home-page: https://github.com/aio-libs/aiohttp
Author: Nikolay Kim
Author-email: fafhrd91@gmail.com
License: Apache 2
Location: /home/vagrant/.local/lib/python3.8/site-packages
Requires: yarl, multidict, attrs, typing-extensions, async-timeout, charde

multidict Version

Name: multidict
Version: 5.1.0
Summary: multidict implementation
Home-page: https://github.com/aio-libs/multidict
Author: Andrew Svetlov
Author-email: andrew.svetlov@gmail.com
License: Apache 2
Location: /home/vagrant/.local/lib/python3.8/site-packages
Requires:
Required-by: yarl, aiohttp

yarl Version

Name: yarl
Version: 1.6.3
Summary: Yet another URL library
Home-page: https://github.com/aio-libs/yarl/
Author: Andrew Svetlov
Author-email: andrew.svetlov@gmail.com
License: Apache 2
Location: /home/vagrant/.local/lib/python3.8/site-packages
Requires: idna, multidict
Required-by: aiohttp

OS

Alpine 3.13 and Alpine 3.14

Related component

Client

Additional context

await content.read() reads partial content under high load #3881
StreamReader.read truncates content #3926

Code of Conduct

• I agree to follow the aio-libs Code of Conduct

[dannmartens]

I managed to do some additional tests, in order to refine my observations.

When files are small enough, there seems to be no issue.

But there's one particular large file, which get truncated and I can reproduce it:

This file should be:

vendors~main.chunk.js len=9149364

But it fails on a CancelledError:

vendors~main.chunk.js len=829575
Traceback (most recent call last):
  File "/home/vcap/proxy.py", line 64, in content_streamer
    chunk = await client_response.content.read(config.CHUNK_SIZE)
  File "/usr/local/lib/python3.8/site-packages/aiohttp/streams.py", line 380, in read
    await self._wait("read")
  File "/usr/local/lib/python3.8/site-packages/aiohttp/streams.py", line 306, in _wait
    await waiter
asyncio.exceptions.CancelledError

[dannmartens]

Might be related to unexpected asyncio.exceptions.CancelledError #5851

[Dreamsorcerer]

That issue is only caused by a timeout on client-side code, but I'm under the impression your code is server-side without a timeout (though you have not given enough code for me to tell for sure). But, feel free to test out #5853.

Server side cancellations are normally caused by a client disconnecting, so maybe there is a difference in how the client is connecting? If you can post a complete example that reproduces the issue, it would be more helpful for people to take a look.

[dannmartens]

I think you're right, but it's not the client of the application: it appears to be the ASGI server itself which breaks the streaming.

I am going to close this issue, because it does not apply to aiohttp. The logs were a red herring: it's just aiohttp responding properly to an outside event. Thank you for pointing that out.

I've reproduced this issue now on different OS + Python combo's, but it's only the ASGI server which was different: it works with Uvicorn, but it fails with Nginx Unit.