Any async delay operation while an aioquic.client object exists makes it silently fail

[ravenblackx]

I initially found this issue while trying to issue a streaming post request; putting a delay between one send_data and the next, such that python was async-awaiting input from stdin, caused this same failure. I've narrowed it down to just any async operation that waits at all, any time during async with client_resolver, causes the same effect.

Reproduction as minimal as I could make it:

import asyncio
import sys
from functools import cached_property
from typing import cast
from urllib.parse import urlparse

import aioquic
from aioquic.asyncio.protocol import QuicConnectionProtocol
from aioquic.h3.connection import H3_ALPN, H3Connection
from aioquic.h3.events import (
    H3Event,)
from aioquic.quic.configuration import QuicConfiguration
from aioquic.quic.events import QuicEvent


class Http3Client(QuicConnectionProtocol):

    @cached_property
    def _http(self) -> H3Connection:
        return H3Connection(self._quic)

    def http_event_received(self, event: H3Event) -> None:
        if event.stream_ended:
            self.future.set_result(True)

    def quic_event_received(self, event: QuicEvent) -> None:
        print('QuicEvent: ', event)
        for http_event in self._http.handle_event(event):
            self.http_event_received(http_event)

    async def request(self, url: str) -> None:
        """Issue an http/3 get request, print response pieces as the packets arrive."""
        stream_id: int = self._quic.get_next_available_stream_id()
        self.future = self._loop.create_future()
        parsed_url = urlparse(url)
        self._http.send_headers(
            stream_id=stream_id,
            headers=[
                (b":method", "GET".encode()),
                (b":scheme", parsed_url.scheme.encode()),
                (b":authority", parsed_url.netloc.encode()),
                (b":path", parsed_url.path.encode()),
            ],
            end_stream=True,
        )

        await self.future


async def main(argv) -> None:
    config = QuicConfiguration(
        is_client=True,
        alpn_protocols=H3_ALPN,
    )
    url = "https://www.google.com/"
    parsed_url = urlparse(url)
    client_resolver = aioquic.asyncio.client.connect(
        host=parsed_url.hostname,
        port=parsed_url.port or 443,
        configuration=config,
        create_protocol=Http3Client,
        wait_connected=True,
    )
    async with client_resolver as client:
        await asyncio.sleep(0.01)  # **** IF YOU COMMENT THIS LINE OUT IT WORKS ****
        client = cast(Http3Client, client)
        await client.request(url)


if __name__ == '__main__':
    sys.exit(asyncio.run(main(sys.argv[1:])))

With the tiny sleep, this outputs

QuicEvent:  ProtocolNegotiated(alpn_protocol='h3')
QuicEvent:  HandshakeCompleted(alpn_protocol='h3', early_data_accepted=False, session_resumed=False)
QuicEvent:  StreamDataReceived(data=b"\x00\x04!\x01\x80\x01\x00\x00\x06\x80\x01\x00\x00\x07@d\x08\x013\x01\xc0\x00\x00\x0ew\xf5'\xb9\xc0\x00\x00\x00q\x95\x13:\xc0\x00\x00\x10\x91\xbd\xf8{\x02ra", end_stream=False, stream_id=3)
QuicEvent:  ConnectionIdIssued(connection_id=b'\x05\xeb\x87;\xdb\x861!')

and gets stuck there until you ctrl-C.

Without the tiny sleep you get essentially the same four lines (different id obviously) but then it goes on to also output the events containing all the HTML and such, and terminate, as expected.

To be clear, if you add debug prints throughout the code, it does everything the same within this script, send_headers is called etc., and waits for the future at the end of the request function, the difference is just that all the expected QuicEvents don't call the callbacks, so that future never completes.

[ravenblackx]

Ah, apparently this is already fixed, I just needed to be on the new version!

[ravenblackx]

Ah, no, it's not fixed, I just mistakenly did (echo && sleep 1 && echo) | h3_request in a context where h3_request took more than a second to start up so there ended up being no async delay.

[jlaine]

I suggest you take a closer look at the http3_client.py example from which your code seems derived. The issue here has nothing to do with sleeping, your client is not sending its HTTP request and eventually times out.

You're missing the call to self.transmit() to actually send the bytes out to the network:

aioquic/examples/http3_client.py

Line 240 in 20cd4ee

self.transmit()

See:

https://aioquic.readthedocs.io/en/latest/asyncio.html#aioquic.asyncio.QuicConnectionProtocol.transmit

[ravenblackx]

In that case isn't there just the opposite bug - if you remove the short sleep it does send the request and get the response even though self.transmit is not called?

[jlaine]

In that case isn't there just the opposite bug - if you remove the short sleep it does send the request and get the response even though self.transmit is not called?

The behaviour is just not defined if you don't call transmit() yourself after queuing data: transmit() can be triggered by receiving data from the server or a timer going off.

[ravenblackx]

Thanks for the explanation, and sorry for the incorrect noise!

[jlaine]

It's not noise, the feedback is welcome. It made me realise that even though the quic (sans IO) layer is reasonably explicit about how it should be used, the asyncio layer is not, much less the interaction with the h3 layer. I think I'll open an issue on this. Would you mind reviewing a proposal for additional docs?

[ravenblackx]

Cool, improved docs are always good. I would suggest that documenting it in transmit might not be the most helpful though - a mention in each of sendData, sendHeaders etc. would be more discoverable. (The problem for me was that I didn't even know the transmit function existed.)