Python 3.5 aiohttp即使使用async/await仍会出现阻塞问题

3
我正在运行一个 aiohttp web 服务器的测试:
#!/usr/bin/env python3

from aiohttp import web
import time
import asyncio
import random
import string
import logging

logger = logging.getLogger('webserver')
logger.setLevel(logging.INFO)
handler = logging.StreamHandler()
formatter = logging.Formatter('%(asctime)s - %(name)s - %(levelname)s - %(message)s')
handler.setFormatter(formatter)
logger.addHandler(handler)

def randomword(length):
    return ''.join(random.choice(string.ascii_lowercase) for i in range(length))

async def hello(request):
    sleeptime = 10 # seconds

    requestid = randomword(5)
    logger.info("Request id: {} received - will sleep for {}".format(requestid, sleeptime))

    await asyncio.sleep(sleeptime)

    logger.info("Request id: {} wakeup and respond".format(requestid))
    return web.json_response()

# create app and register with request handler
app = web.Application()
app.router.add_get('/', hello)
web.run_app(app, port='15000')

这个程序预期可以同时处理多个请求,而不必等待一个请求完成后再处理下一个请求。然而,它没有做到这一点 - 处理是顺序的(请注意第二/第三个请求的开始时间在前几个请求完成之后):

======== Running on http://0.0.0.0:15000/ ========
(Press CTRL+C to quit)
2016-10-23 02:28:23,911 - webserver - INFO - Request id: hpzdo received - will sleep for 10
2016-10-23 02:28:33,922 - webserver - INFO - Request id: hpzdo wakeup and respond
2016-10-23 02:28:33,947 - webserver - INFO - Request id: pdfbs received - will sleep for 10
2016-10-23 02:28:43,957 - webserver - INFO - Request id: pdfbs wakeup and respond
2016-10-23 02:28:43,971 - webserver - INFO - Request id: dmkav received - will sleep for 10
2016-10-23 02:28:53,982 - webserver - INFO - Request id: dmkav wakeup and respond

我希望每个请求的开始时间几乎相同(取决于我提交它们的速度;此处我手动提交需要一两秒钟)。


你是如何发起请求的?并非所有客户端都允许同时向相同的URL发起请求。 - dirn
我通过在Firefox中同时打开三个标签页并快速循环切换它们并刷新页面来发出请求(所有三个标签页的URL均为http://localhost:15000)。 - Soumen Dass
我认为Firefox是不会对同一URL发出并发请求的客户端之一。使用更适合测试的工具(比如@Andrew Svetlov的回答中提到的)应该能够展示您期望的行为。 - dirn
@dirn确实 - 我使用了curl/wrk,现在行为符合预期。如果我知道这个Firefox的行为,我本可以节省很多时间。 - Soumen Dass
1个回答

2

你的测试技术存在问题。

使用 wrk 工具对你的服务器进行测试会得到不同的结果。

运行命令:

wrk http://127.0.0.1:15000/  

服务器输出:

======== Running on http://0.0.0.0:15000 ========
(Press CTRL+C to quit)
2016-10-23 14:58:56,447 - webserver - INFO - Request id: hkkrp received - will sleep for 10
2016-10-23 14:58:56,447 - webserver - INFO - Request id: cysoy received - will sleep for 10
2016-10-23 14:58:56,448 - webserver - INFO - Request id: udwxe received - will sleep for 10
2016-10-23 14:58:56,448 - webserver - INFO - Request id: moqkf received - will sleep for 10
2016-10-23 14:58:56,449 - webserver - INFO - Request id: shetp received - will sleep for 10
2016-10-23 14:58:56,450 - webserver - INFO - Request id: fhilc received - will sleep for 10
2016-10-23 14:58:56,451 - webserver - INFO - Request id: birax received - will sleep for 10
2016-10-23 14:58:56,452 - webserver - INFO - Request id: yyeoc received - will sleep for 10
2016-10-23 14:58:56,453 - webserver - INFO - Request id: mpkwf received - will sleep for 10
2016-10-23 14:58:56,454 - webserver - INFO - Request id: nkxiz received - will sleep for 10
2016-10-23 14:59:06,450 - webserver - INFO - Request id: hkkrp wakeup and respond
2016-10-23 14:59:06,451 - webserver - INFO - Request id: cysoy wakeup and respond
2016-10-23 14:59:06,451 - webserver - INFO - Request id: udwxe wakeup and respond
2016-10-23 14:59:06,452 - webserver - INFO - Request id: moqkf wakeup and respond
2016-10-23 14:59:06,452 - webserver - INFO - Request id: shetp wakeup and respond
2016-10-23 14:59:06,453 - webserver - INFO - Request id: fmpmm received - will sleep for 10
2016-10-23 14:59:06,453 - webserver - INFO - Request id: uusnt received - will sleep for 10
2016-10-23 14:59:06,453 - webserver - INFO - Request id: kjlzk received - will sleep for 10
2016-10-23 14:59:06,453 - webserver - INFO - Request id: elhje received - will sleep for 10
2016-10-23 14:59:06,453 - webserver - INFO - Request id: bkvjp received - will sleep for 10
2016-10-23 14:59:06,454 - webserver - INFO - Request id: fhilc wakeup and respond
2016-10-23 14:59:06,454 - webserver - INFO - Request id: birax wakeup and respond
2016-10-23 14:59:06,454 - webserver - INFO - Request id: yyeoc wakeup and respond
2016-10-23 14:59:06,455 - webserver - INFO - Request id: nyhba received - will sleep for 10
2016-10-23 14:59:06,455 - webserver - INFO - Request id: iqjvr received - will sleep for 10
2016-10-23 14:59:06,455 - webserver - INFO - Request id: osfsg received - will sleep for 10
2016-10-23 14:59:06,455 - webserver - INFO - Request id: mpkwf wakeup and respond
2016-10-23 14:59:06,456 - webserver - INFO - Request id: nkxiz wakeup and respond
2016-10-23 14:59:06,456 - webserver - INFO - Request id: ebzai received - will sleep for 10
2016-10-23 14:59:06,456 - webserver - INFO - Request id: erfhe received - will sleep for 10

谢谢。我认为在Firefox中手动提交请求时出现了一些奇怪的问题。我尝试使用wrk,确实可以正常工作。 - Soumen Dass
我们有任何线索吗?如果我手动使用浏览器提交请求,行为是否相同。 - argaen
也许一个浏览器在选项卡之间共享与相同URI的相同连接。 尝试使用不同的浏览器实例。 - Andrew Svetlov

网页内容由stack overflow 提供, 点击上面的
可以查看英文原文,
原文链接