Random Timeout Fehler mit Heroku + Gunicorn + Aiohttp

Question

Ich habe einen Dienst, der als ein Gateway zum Umleiten von Anforderungen an verschiedene Micro-Services fungiert. Um dies zu tun, habe ich aiohttp verwendet, um eine Redirect-Anfragen, Gunicorn (w/aiohttp.worker.GunicornWebWorker) zu bedienen und Heroku als Host.

Arbeiten in lokalen alles funktioniert perfekt, 100% Anfragen eine Antwort zurück und der Client erhält immer die gewünschten Informationen aber wenn ich auf Heroku bereitstellen und einige Anfragen umleiten (5k pro Minute) sehe ich zwischen 3 bis 7 Anfragen mit HTTP-Status 503 Zeitüberschreitungsfehler. Es ist nichts, worüber man sich Sorgen machen muss, weil der Anteil gut beantworteter Anfragen sehr hoch ist (99,9994), aber ich möchte wissen, was passiert. Die Ausnahme Anheben kurz vor den Timeouts ist wie folgt:

[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) 

Dann Heroku/Router zeigt ein Fehler wie folgt aus:

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 

Ich bin mit der App mit:

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

Der Hauptcode lautet:

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) 

Und eine Umleitung Beispiel:

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)) 

Wie Sie ein Timeout von 25s gibt es bei der Herstellung der Anfragen und die Ausnahme mit 30s Timeout erzieht zu sehen.

Jeder, der Ahnung hat, was passiert?

(Anmerkung: Wenn ich umleiten schreibe ich meine nicht HTTP sagen, 302 ich die Anfrage bedeuten behandeln, bearbeiten Header, Auth überprüfen, Asynchron-Anfrage an die zuständige MS, Griff Reaktion zu machen und senden Sie diese Antwort)

Answer 1

Am Ende war das Problem in einem der Handler. Ich weiß nicht wirklich, was passiert, weil die Timeouts für alle Endpunkte völlig zufällig waren, aber nach 6 Stunden, die perfekt mit mehr als 10k Anfragen pro Minute funktionieren, bin ich sicher, dass das Problem das war. Hier ist der Code vor und nach dem Update:

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) 

Wie Sie der einzige Unterschied sehen kann, ist, dass in einem Fall, dass wir den Körper immer warten und im anderen Fall nicht.

Ich werde die Frage offen lassen, nur hopping jemand antwortet mir, warum es jetzt funktioniert. :)