隨機超時使用heroku + gunicorn + aiohttp的錯誤

我開發了一個服務，充當網關，將請求重定向到不同的微服務。爲此，我使用aiohttp來處理重定向請求，gunicorn（w/aiohttp.worker.GunicornWebWorker）服務，Heroku作爲主機。隨機超時使用heroku + gunicorn + aiohttp的錯誤

在本地工作一切都很完美，100％的請求返回響應，客戶端總是收到所需的信息，但是當我部署到Heroku並重定向一些請求時（每分鐘5k），我發現有3到7個HTTP狀態請求503超時錯誤。沒什麼好擔心的，因爲好的解決請求比例非常高（99.9994），但我想知道發生了什麼。該異常引發只是超時之前是這樣的：

[2017-02-10 17:03:48 +0000] [683] [INFO] Worker exiting (pid: 683) 
ERROR:asyncio:Task was destroyed but it is pending! 
[2017-02-10 17:03:48 +0000] [683] [INFO] Stopping server: 683, connections: 1 
Exception ignored in: <generator object GunicornWebWorker._run at 0x7f18b1d2f518> 
Traceback (most recent call last): 
    yield from self.close() 
    yield from self.wsgi.shutdown() 
File "/app/.heroku/python/lib/python3.5/site-packages/aiohttp/web.py", line 199, in shutdown 
    yield from self.on_shutdown.send(self) 
File "/app/.heroku/python/lib/python3.5/site-packages/aiohttp/signals.py", line 48, in send 
    yield from self._send(*args, **kwargs) 
File "/app/.heroku/python/lib/python3.5/site-packages/aiohttp/signals.py", line 16, in _send 
    yield from res 
File "/app/app/app.py", line 14, in close_redis 
    app.redis_pool.close() 
File "/app/.heroku/python/lib/python3.5/site-packages/aioredis/pool.py", line 135, in close 
    self._close_state.set() 
File "/app/.heroku/python/lib/python3.5/asyncio/locks.py", line 242, in set 
    fut.set_result(True) 
File "/app/.heroku/python/lib/python3.5/asyncio/futures.py", line 332, in set_result 
    self._schedule_callbacks() 
File "/app/.heroku/python/lib/python3.5/asyncio/futures.py", line 242, in _schedule_callbacks 
    self._loop.call_soon(callback, self) 
File "/app/.heroku/python/lib/python3.5/asyncio/base_events.py", line 497, in call_soon 
    handle = self._call_soon(callback, args) 
File "/app/.heroku/python/lib/python3.5/asyncio/base_events.py", line 506, in _call_soon 
    self._check_closed() 
File "/app/.heroku/python/lib/python3.5/asyncio/base_events.py", line 334, in _check_closed 
    raise RuntimeError('Event loop is closed') 
RuntimeError: Event loop is closed 
ERROR:asyncio:Task was destroyed but it is pending! 
task: <Task pending coro=<ServerHttpProtocol.start() running at /app/.heroku/python/lib/python3.5/site-packages/aiohttp/server.py:261>> 
[2017-02-10 17:03:48 +0000] [4] [CRITICAL] WORKER TIMEOUT (pid:683)

隨後的Heroku /路由器顯示這樣的錯誤：

at=error code=H12 desc="Request timeout" method=GET path="https://stackoverflow.com/users/21324/posts/" host=superapp.herokuapp.com request_id=209bd839-baac-4e72-a04e-657d85348f45 fwd="84.78.56.97" dyno=web.2 connect=0ms service=30000ms status=503 bytes=0

我運行的應用程序有：

gunicorn --pythonpath app app.app:aio_app --worker-class aiohttp.worker.GunicornWebWorker --workers 3

主要代碼是：

def init(asyncio_loop): 
    app = web.Application(loop=asyncio_loop, middlewares=[middlewares.auth_middleware, 
                  middlewares.logging_middleware]) 

    # INIT DBs 
    app.redis_pool = asyncio_loop.run_until_complete(
     create_pool((settings.REDIS['host'], settings.REDIS['port']), 
        password=settings.REDIS['password'])) 

    # Clean connections on stop 
    app.on_shutdown.append(close_redis) 

    # Add rollbar 
    rollbar.init(settings.ROLLBAR_TOKEN, 'production') # access_token, environment 

    # Bind routes 
    for r in routes: 
     app.router.add_route(r[0], r[1], r[2]) 

    return app 


# Create app 
loop = asyncio.get_event_loop() 
aio_app = init(loop)

以及重定向例如：

async with aiohttp.ClientSession() as s: 
    try: 
     async with s.request(method=method, 
          url=new_url, 
          headers=new_headers, 
          data=body, 
          allow_redirects=False, 
          timeout=25) as response: 
      # Clean response 
      resp_headers = MSRepository.filter_response_headers(response.headers) 
      resp_body = (await response.read()) 

      return ResponseDataEntity(resp_headers, response.status, resp_body) 
    except asyncio.TimeoutError: 
     raise MSConnectionError("Request timeout") 
    except Exception as e: 
     rollbar.report_message(str(e), extra_data={ 
      "url": new_url, 
      "data": body, 
      "method": method, 
      "headers": new_headers 
     }) 
     raise MSConnectionError(str(e))

正如你可以看到有25秒的超時發出請求和異常與超時30秒時提高。

任何人都有任何線索發生了什麼？

（注：當我寫改向我的意思並不是說HTTP 302我的意思是處理該請求，編輯標題，檢查權威性，使異步請求中選取適當的MS，處理響應和返回該響應）

來源

2017-02-10 Jairo Vadillo

最後問題出現在一個處理程序中。我不知道發生了什麼，因爲超時對於所有端點是完全隨機的，但是在6小時完成超過10k個請求後，我確信問題是這樣。下面是代碼之前和修復程序後：

async def bad_handler(request): 
    # Read body in ALL cases to not to block requests 
    if '/event-log/action/' == request.path: 
     if request.query_string != '': 
      action_type = request.query_string 
     else: 
      try: 
       request_body = await request.json() 
       action_type = request_body.get('type', '') 
      except: 
       action_type = '' 

     print("Action_type={}".format(action_type)) 

    # Response to client 
    return aiohttp.web.json_response(data={}, status=200) 

async def good_handler(request): 
    # Read body in ALL cases to not to block requests 
    try: 
     request_body = await request.json() 
    except: 
     request_body = None 

    if '/event-log/action/' == request.path: 
     if request.query_string != '': 
      action_type = request.query_string 
     else: 
      if request_body is not None: 
       action_type = request_body.get('type', '') 
      else: 
       action_type = '' 

     print("Action_type={}".format(action_type)) 

    # Response to client 
    return aiohttp.web.json_response(data={}, status=200)

正如你看到的，唯一的區別是，在一個情況下，我們一直在等待身體和在其他情況下沒有。

我將離開這個問題打開只是跳一個人回答我爲什麼現在工作。 :)

來源

2017-02-23 16:47:37

隨機超時使用heroku + gunicorn + aiohttp的錯誤

回答

相關問題