Process stop listening on tcp port when multiple tasks are running on the same event loop

[rudineirk]

• uvloop version: 0.8.0
• python version: 3.6.0
• platform: Fedora 25

I was trying to create a HTTP service that connects to a mongo database to provide a CRUD API, that implemented some logic to reconnect to the mongo database if the connection was not available when the process started.

The problem I found is that the process stops listening on the HTTP TCP port after the first timeout of the connection to the mongo database. The problem does not happen when I use the default python event loop. I was trying to use the sanic library to implement the HTTP API, but the problem also happened when I switched to the aiohttp.web library, so this problem probably is not linked to a specific library code.

Here are the libraries versions that I used and the code that causes the problem:

• sanic version: 0.4.1
• motor version: 1.1
• pymongo version: 3.4.0

import asyncio
import uvloop
from sanic import Sanic
from sanic.response import json
from motor.motor_asyncio import AsyncIOMotorClient
from pymongo.errors import CollectionInvalid, ServerSelectionTimeoutError

DB_NAME = 'testdb'
COLLECTION_NAME = 'testcoll'

asyncio.set_event_loop_policy(uvloop.EventLoopPolicy())

loop = asyncio.get_event_loop()
conn = AsyncIOMotorClient(
    host='127.0.0.1',
    port=27017,
    connectTimeoutMS=2000,
    serverSelectionTimeoutMS=5000,
)
db = conn['testdb']
collection = db['testcoll']

app = Sanic()


async def start_db():
    print('connecting to mongodb!')
    try:
        await db.create_collection(COLLECTION_NAME)
    except CollectionInvalid:
        pass
    except ServerSelectionTimeoutError:
        await asyncio.sleep(0.5)
        print('trying to connect to mongodb again...')
        loop.create_task(start_db())
        return

    # Indexes are supposed to be created here

    print('connected to mongodb!')


@app.route('/')
async def handler(request):
    data = await collection.find().to_list(None)
    return json(data)


def main():
    server = app.create_server(
        host='127.0.0.1',
        port=5000,
        debug=True,
        loop=loop,
    )
    loop.create_task(start_db())
    asyncio.ensure_future(server, loop=loop)

    # Start other asyncio things here
    loop.run_forever()


if __name__ == '__main__':
    main()

EDIT: forgot to add the output log

output:

connecting to mongodb!
~/.local/lib/python3.6/site-packages/sanic/app.py:524: DeprecationWarning: Passing a loop will be deprecated in version 0.4.0 https://github.com/channelcat/sanic/pull/335 has more information.
  DeprecationWarning)
2017-03-06 16:15:19,518: DEBUG:
sanic drawing here
2017-03-06 16:15:19,518: INFO: Goin' Fast @ http://127.0.0.1:5000
trying to connect to mongodb again...
/usr/lib64/python3.6/traceback.py:352: ResourceWarning: unclosed resource <TCPServer closed=False 0x7f7dcbf4b448>; object created at (most recent call last):
  File "example_sanic.py", line 64, in <module>
    main()
  File "example_sanic.py", line 60, in main
    loop.run_forever()
  File "~/.local/lib/python3.6/site-packages/sanic/app.py", line 509, in create_server
    return await serve(**server_settings)
  filename, lineno, name, lookup_line=False, locals=f_locals))
connecting to mongodb!
trying to connect to mongodb again...

[bright-pan]

hi,

i test it but i can`t reproduct it.

connecting to mongodb!
/Users/jason/.pyenv/versions/pulsar-env/lib/python3.6/site-packages/sanic/sanic.py:454: DeprecationWarning: Passing a loop will be deprecated in version 0.4.0 https://github.com/channelcat/sanic/pull/335 has more information.
  DeprecationWarning)
2017-03-18 09:50:53,717: DEBUG: 
                 ▄▄▄▄▄
        ▀▀▀██████▄▄▄       _______________
      ▄▄▄▄▄  █████████▄  /                 \
     ▀▀▀▀█████▌ ▀▐▄ ▀▐█ |   Gotta go fast!  |
   ▀▀█████▄▄ ▀██████▄██ | _________________/
   ▀▄▄▄▄▄  ▀▀█▄▀█════█▀ |/
        ▀▀▀▄  ▀▀███ ▀       ▄▄
     ▄███▀▀██▄████████▄ ▄▀▀▀▀▀▀█▌
   ██▀▄▄▄██▀▄███▀ ▀▀████      ▄██
▄▀▀▀▄██▄▀▀▌████▒▒▒▒▒▒███     ▌▄▄▀
▌    ▐▀████▐███▒▒▒▒▒▐██▌
▀▄▄▄▄▀   ▀▀████▒▒▒▒▄██▀
          ▀▀█████████▀
        ▄▄██▀██████▀█
      ▄██▀     ▀▀▀  █
     ▄█             ▐▌
 ▄▄▄▄█▌              ▀█▄▄▄▄▀▀▄
▌     ▐                ▀▀▄▄▄▀
 ▀▀▄▄▀

2017-03-18 09:50:53,717: INFO: Goin' Fast @ http://127.0.0.1:5000
2017-03-18 09:50:53,717: INFO: Goin' Fast @ http://127.0.0.1:5000
connected to mongodb!

[rudineirk]

You have to start the application without mongodb running (or with an invalid host), the problem happens after the first connection retry (about 5 seconds after the process started)

[1st1]

This happens because you don't save a reference to the server object that app.create_server returns. If you replace asyncio.ensure_future(server, loop=loop) with srv = loop.run_until_complete(server), everything should work as expected.

Anyways, this is something where asyncio and uvloop behave a bit differently. I'll fix this in the next release.

[1st1]

Fixed in master, will be in the next release (soon)

[1st1]

Please try uvloop v0.9.0.