noirello / bonsai

Simple Python 3 module for LDAP, using libldap2 and winldap C libraries.
MIT License
116 stars 32 forks source link

When LDAP server unavailable whole application freezes #41

Closed hh-h closed 3 years ago

hh-h commented 3 years ago

Hello,

I found nasty bug that freezes my application :(
Steps to reproduce:

import asyncio
import time

import bonsai

async def connect():
    client = bonsai.LDAPClient(f"ldap://8.8.8.8")
    async with client.connect(is_async=True, timeout=3):
        return True

async def printer():
    while True:
        print(f"{time.time()} hi")
        await asyncio.sleep(1)

async def main():
    asyncio.create_task(printer())
    await asyncio.sleep(3)
    await connect()

asyncio.run(main())
1596881355.416916 hi
1596881356.420735 hi
1596881357.4230669 hi
Traceback (most recent call last):
  File ".../script_bonsai.py", line 25, in <module>
    asyncio.run(main())
  File "/Library/Frameworks/Python.framework/Versions/3.7/lib/python3.7/asyncio/runners.py", line 43, in run
    return loop.run_until_complete(main)
  File "/Library/Frameworks/Python.framework/Versions/3.7/lib/python3.7/asyncio/base_events.py", line 583, in run_until_complete
    return future.result()
  File ".../script_bonsai.py", line 22, in main
    await connect()
  File ".../script_bonsai.py", line 9, in connect
    async with client.connect(is_async=True, timeout=3):
  File ".../lib/python3.7/site-packages/bonsai/asyncio/aioconnection.py", line 30, in __aenter__
    return await self.__open_coro
  File ".../lib/python3.7/site-packages/bonsai/asyncio/aioconnection.py", line 63, in _poll
    raise exc
  File ".../lib/python3.7/site-packages/bonsai/asyncio/aioconnection.py", line 59, in _poll
    return await asyncio.wait_for(fut, timeout)
  File "/Library/Frameworks/Python.framework/Versions/3.7/lib/python3.7/asyncio/tasks.py", line 442, in wait_for
    return fut.result()
  File ".../lib/python3.7/site-packages/bonsai/asyncio/aioconnection.py", line 45, in _ready
    res = super().get_result(msg_id)
bonsai.errors.ConnectionError: Can't contact LDAP server. (0xFFFF [-1])
1596881434.8999639 hi

Process finished with exit code 1

I think super().get_result(msg_id) should be executed in run_in_executor with wait_for

noirello commented 3 years ago

Hi,

On Mac by default the created socket for the LDAP connection doesn't have the non-blocking flag set. You can change it with bonsai.set_connect_async(True), but I've experienced more issues with TLS connections, when it was set.

Using Linux (where the async connection enabled by default), your example code should time out properly after 3 seconds, while keep printing the other coroutine's text.

Also, there is some extra explanations in this issue about this.

hh-h commented 3 years ago

Unfortunately, that's not true

1596883055.7814884 hi
1596883056.7828977 hi
1596883057.7843115 hi
1596883185.9830725 hi
Traceback (most recent call last):
  File "script_bonsai.py", line 25, in <module>
    asyncio.run(main())
  File "/usr/lib/python3.7/asyncio/runners.py", line 43, in run
    return loop.run_until_complete(main)
  File "/usr/lib/python3.7/asyncio/base_events.py", line 579, in run_until_complete
    return future.result()
  File "script_bonsai.py", line 22, in main
    await connect()
  File "script_bonsai.py", line 9, in connect
    async with client.connect(is_async=True, timeout=3):
  File ".../lib/python3.7/site-packages/bonsai/asyncio/aioconnection.py", line 30, in __aenter__
    return await self.__open_coro
  File ".../lib/python3.7/site-packages/bonsai/asyncio/aioconnection.py", line 64, in _poll
    raise exc
  File ".../lib/python3.7/site-packages/bonsai/asyncio/aioconnection.py", line 59, in _poll
    return await asyncio.wait_for(fut, timeout)
  File "/usr/lib/python3.7/asyncio/tasks.py", line 442, in wait_for
    return fut.result()
  File ".../lib/python3.7/site-packages/bonsai/asyncio/aioconnection.py", line 45, in _ready
    res = super().get_result(msg_id)
bonsai.errors.ConnectionError: Can't contact LDAP server. (0xFFFF [-1])

I believe it is python:3.7 image that runs in docker

uname -a
Linux f8bf63cb8d2f 3.16.0-4-amd64 #1 SMP Debian 3.16.7-ckt25-2 (2016-04-08) x86_64 x86_64 x86_64 GNU/Linux
noirello commented 3 years ago

It's weird. This is what I get when I run your example in a python:3.7 docker container:

# python3 test.py
1597082424.9970446 hi
1597082425.9984224 hi
1597082426.9998264 hi
1597082428.003627 hi
1597082429.0049498 hi
1597082430.0063202 hi
Traceback (most recent call last):
  File "test.py", line 21, in <module>
    asyncio.run(main())
  File "/usr/local/lib/python3.7/asyncio/runners.py", line 43, in run
    return loop.run_until_complete(main)
  File "/usr/local/lib/python3.7/asyncio/base_events.py", line 587, in run_until_complete
    return future.result()
  File "test.py", line 19, in main
    await connect()
  File "test.py", line 8, in connect
    async with client.connect(is_async=True, timeout=3):
  File "/usr/local/lib/python3.7/site-packages/bonsai/asyncio/aioconnection.py", line 30, in __aenter__
    return await self.__open_coro
  File "/usr/local/lib/python3.7/site-packages/bonsai/asyncio/aioconnection.py", line 64, in _poll
    raise exc
  File "/usr/local/lib/python3.7/site-packages/bonsai/asyncio/aioconnection.py", line 59, in _poll
    return await asyncio.wait_for(fut, timeout)
  File "/usr/local/lib/python3.7/asyncio/tasks.py", line 449, in wait_for
    raise futures.TimeoutError()
concurrent.futures._base.TimeoutError
# cat test.py
import asyncio
import time

import bonsai

async def connect():
    client = bonsai.LDAPClient(f"ldap://8.8.8.8")
    async with client.connect(is_async=True, timeout=3):
        return True

async def printer():
    while True:
        print(f"{time.time()} hi")
        await asyncio.sleep(1)

async def main():
    asyncio.create_task(printer())
    await asyncio.sleep(3)
    await connect()

asyncio.run(main())

But the output of the uname is quite differrent:

# uname -a
Linux a1d38127a5b0 4.19.76-linuxkit #1 SMP Tue May 26 11:42:35 UTC 2020 x86_64 GNU/Linux

I'm not sure why.

Could you tell me the vendor version of the libldap that you're using?

>>> import bonsai
>>> bonsai.__version__
'1.2.0'
>>> bonsai.get_vendor_info()
('OpenLDAP', 20447)
hh-h commented 3 years ago
In [1]: import  bonsai

In [2]: bonsai.__version__
Out[2]: '1.2.0'

In [3]: bonsai.get_vendor_info()
Out[3]: ('OpenLDAP', 20442)
noirello commented 3 years ago

The non-blocking socket settings are only available from 20444 (OpenLDAP 2.4.44). Prior to that version even non-tls connections were flaky with the non-blocking flag. Can you update to a newer OpenLDAP?

hh-h commented 3 years ago

Unfortunately, I cannot update right now, but I tested on fresh Debian, it works fine. Probably it should be noted somewhere in README I think.

Also, why not run_in_executor as I mentioned before?

noirello commented 3 years ago

I'll update the docs about it.

I've never considered to use run_in_executor before, mostly tried to rely on what libldap provides for async. I wouldn't execute the super().get_result(msg_id) method in a separate thread, because after the connection is set it's unnecessary (even without setting the socket to non-blocking). Polling the result of an LDAP operation (which is done by the same get_result(msg_id) method) works without blocking.