Httpx 5 second delay

Đang mở
  • Có gì không ổn?
#804 1 bình luận 0 reaction 0 người được giao Xem trên GitHub

Maintainer thường phản hồi trong vòng 1 ngày

Chưa có ai nhận issue này.

Đánh giá

Độ khó
4/5
Thời gian dự kiến
3-5 ngày
Mức phù hợp với người mới
42/100
Loại issue
Lỗi
Độ rõ ràng
Cần làm rõ
Mức độ hoạt động
Ít trao đổi
Công nghệ
python
Lĩnh vực
backend, networking

Hướng nghiên cứu

Bắt đầu với handler get_all_sites_health và hàm perform_get_probe được cung cấp, tái hiện các yêu cầu đồng thời đến khoảng 100 URL bằng httpx và so sánh chúng với aiohttp. Theo dõi hành vi DNS và kết nối dưới tải này; được xem là hoàn tất khi đã xác định được nguyên nhân của các độ trễ lặp lại năm giây và các lỗi DNS của Docker, đồng thời hành vi bị ảnh hưởng được bao phủ bởi một kiểm tra hồi quy phù hợp.

Do mô hình lập chỉ mục viết ra từ nội dung của issue.

Mô tả

Originally opened by @dhensen on 2023-12-15 22:05:14 in encode/httpx

Hi all,

Httpx version: I'm still on httpx 24.1 because I had to downgrade because of https://github.com/encode/httpx/pull/2929

Expectation:

I expect my http calls not to get delayed by a constant 5 seconds.

Actual:

My http calls are delayed with a constant 5 seconds, plus I get DNS related logs from dockerd.

Long story

I noticed in my system logs weird docker dns issues:

Click to see logs 
Dec 15 22:53:44 my-hostname dockerd[1601]: time="2023-12-15T22:53:44.285539223+01:00" level=error msg="[resolver] failed to query DNS server: 192.168.50.1:53, query: ;gameboy2023.my-site-ommitted.nl.\tIN\t AAAA" error="read udp 172.28.0.3:53713->192.168.50.1:53: i/o timeout"
Dec 15 22:53:44 my-hostname dockerd[1601]: time="2023-12-15T22:53:44.296076826+01:00" level=error msg="[resolver] failed to query DNS server: 1.1.1.1:53, query: ;ht.my-site-ommitted.nl.\tIN\t A" error="read udp 172.28.0.105:43077->1.1.1.1:53: i/o timeout"
Dec 15 22:53:44 my-hostname dockerd[1601]: time="2023-12-15T22:53:44.296120525+01:00" level=error msg="[resolver] failed to query DNS server: 1.1.1.1:53, query: ;ht.my-site-ommitted.nl.\tIN\t AAAA" error="read udp 172.28.0.105:60254->1.1.1.1:53: i/o timeout"
Dec 15 22:53:44 my-hostname dockerd[1601]: time="2023-12-15T22:53:44.305453453+01:00" level=error msg="[resolver] failed to query DNS server: 192.168.50.1:53, query: ;theultimatenerdconf.my-site-ommitted.nl.\tIN\t AAAA" error="read udp 172.28.0.3:49108->192.168.50.1:53: i/o timeout"
Dec 15 22:53:48 my-hostname dockerd[1601]: time="2023-12-15T22:53:48.364826590+01:00" level=error msg="[resolver] failed to query DNS server: 192.168.50.1:53, query: ;zongaatonder.my-site-ommitted.nl.\tIN\t AAAA" error="read udp 172.28.0.3:48923->192.168.50.1:53: i/o timeout"
Dec 15 22:53:48 my-hostname dockerd[1601]: time="2023-12-15T22:53:48.366090453+01:00" level=error msg="[resolver] failed to query DNS server: 192.168.50.1:53, query: ;top10movies.my-site-ommitted.nl.\tIN\t AAAA" error="read udp 172.28.0.3:56201->192.168.50.1:53: i/o timeout"
Dec 15 22:53:52 my-hostname dockerd[1601]: time="2023-12-15T22:53:52.496770882+01:00" level=error msg="[resolver] failed to query DNS server: 192.168.50.1:53, query: ;gameboy2023.my-site-ommitted.nl.\tIN\t AAAA" error="read udp 172.28.0.3:49707->192.168.50.1:53: i/o timeout"
Dec 15 22:53:52 my-hostname dockerd[1601]: time="2023-12-15T22:53:52.508179669+01:00" level=error msg="[resolver] failed to query DNS server: 192.168.50.1:53, query: ;ergotherapie2.my-site-ommitted.nl.\tIN\t AAAA" error="read udp 172.28.0.3:51178->192.168.50.1:53: i/o timeout"
Dec 15 22:53:56 my-hostname dockerd[1601]: time="2023-12-15T22:53:56.515096544+01:00" level=error msg="[resolver] failed to query DNS server: 192.168.50.1:53, query: ;theultimatenerdconf.my-site-ommitted.nl.\tIN\t AAAA" error="read udp 172.28.0.3:33374->192.168.50.1:53: i/o timeout"
Dec 15 22:53:56 my-hostname dockerd[1601]: time="2023-12-15T22:53:56.590845767+01:00" level=error msg="[resolver] failed to query DNS server: 192.168.50.1:53, query: ;zongaatonder.my-site-ommitted.nl.\tIN\t AAAA" error="read udp 172.28.0.3:60863->192.168.50.1:53: i/o timeout"

It always used to happen when I was doing health probes on about a 100 websites asynchronous as the same moment. I discovered this issue 2 weeks ago, but today got the time to dig into this. I suspected it was httpx, but I had no proof other than running into long timeouts for http calls to sites that were supposed to be fast.

I also ran while true; do dig "https://$(tr -dc 'a-zA-Z0-9' </dev/urandom | head -c 10).my-site-ommittedd.nl"; done on my host and inside docker on that same host to see if there is a docker related DNS issue. Running this large amount of DNS lookups do not result into the same system logs I saw from when my api was doing lookups using httpx. So httpx became my prime suspect.

I then changed up my implementation to retrieve all my site urls (there are a little over 100 in db) and make it so I can swap httpx for aiohttp (I'm sorry, I can image reading this hurts 💔 )

With aiohttp my problem disappears and I get normal response times. All 106 response times are below 1.2 seconds, with the lowest being 0.07.

With httpx about 64 out of 106 come with the 5.xx seconds (out of 106 calls only 1 fails, so no TimeoutException) AND system logs appear. Now I think those logs are trying to tell that the dns query wasn't read, hence the i/o timeout at the end of each log line.

So my bug is about what is httpx doing with regards to DNS? What could lead to the issues I'm describing.

This is an excerpt of my code (based on Sanic):

async def get_all_site_urls(conn):
    async with conn.cursor(aiomysql.DictCursor) as cur:
        await cur.execute("SELECT site_url FROM site_config")
        site_configs = await cur.fetchall()
        return [x["site_url"] for x in site_configs]


`@app`.get("/all_sites_health/<client_type>", name="get all sites health")
async def get_all_sites_health(request, client_type: str):
    site_urls = await get_all_site_urls(request.ctx.conn)
    # TODO set better timeouts on teh http clients, use defaults for now
    if client_type == "aiohttp":
        http_client_cls = aiohttp.ClientSession
        # timeout 5 seconds per conn/read/write/pool
    else:
        http_client_cls = httpx.AsyncClient
        # timeout 300 seconds by default

    async with http_client_cls() as http_client:
        tasks = []
        for url in site_urls:
            task = asyncio.create_task(perform_get_probe(http_client, url))
            tasks.append(task)
        results = await asyncio.gather(*tasks)
    return response.json({"res": results})


async def perform_get_probe(http_client, site_url: str):
    start = perf_counter()
    try:
        res = await http_client.get(site_url)
        try:
            healthy = res.status_code == 200  # httpx
        except AttributeError:
            healthy = res.status == 200  # aiohttp
    except (httpx.RequestError, aiohttp.ClientError):
        healthy = False

    duration = perf_counter() - start
    return site_url, healthy, duration
Ngôn ngữ chính
Python
Star
1.6k
Fork
103
Merge trung bình
1 ngày 19 giờ
Pull request đã merge (30 ngày)
25

Chuẩn bị môi trường

Bắt đầu từ đâu

  1. Đọc hết issue, rồi đọc hướng dẫn đóng góp của dự án.
  2. Bình luận trên issue rằng bạn sẽ nhận — tránh hai người làm cùng một việc.
  3. Fork repository và làm thay đổi trên một nhánh.
  4. Mở pull request có tham chiếu số hiệu của issue.

Issue khác của pydantic/httpx2

Tất cả issue của pydantic/httpx2

Issue tương tự

Thêm issue về Python

Nhận issue mới trong hộp thư của bạn

Bản tóm tắt ngắn những issue GitHub phù hợp với người mới.