python-ldap-dev

problem with modify using python-ldap

[Allan S. <as...@in...>]

Using python-ldap-python-ldap-2.0.0pre04 with Python 2.2.1, and OpenLDAP
2.0.23 on RedHat Linux.

Deleting and adding an attribute is taking 9 seconds.  The same actions
using ldapmodify(1) on the command line complete virtually instantly.

Oddly, the behavior does not manifest if log level 1 (trace function
calls) is enabled.  Here is a log snip at level 6 (heavy trace debugging
plus debug packet handling).  This first snip is with ldapmodify(1) as the
client:

    do_modify: dn (iuEduUPID=9900000004,ou=people,dc=iu,dc=edu)
    modifications:
            delete: iuEduMailDeliveryTo
            add: iuEduMailDeliveryTo
    ldbm_back_modify:
    ldbm_modify_internal: delete
    removing entire attribute iuEduMailDeliveryTo
    ldbm_modify_internal: add
    ldbm_modify_internal: replace
    ldbm_modify_internal: replace
    send_ldap_result: 0::

Now with python-ldap's modify_s operation as the client:

    do_modify: dn (iuEduUPID=9900000004,ou=people,dc=iu,dc=edu)
    modifications:
            delete: iuEduMailDeliveryTo
            add: iuEduMailDeliveryTo
    ldbm_back_modify:
    ldbm_modify_internal: delete
    removing entire attribute iuEduMailDeliveryTo
    ldbm_modify_internal: add
    ldbm_modify_internal: replace
    ldbm_modify_internal: replace
    ldap_read: want=1 error=Resource temporarily unavailable
 **** hangs for about 9 seconds here ****
    send_ldap_result: 0::

Ultimately the modifications succeed.  The difference I see is that
"Resource temporarily unavailable" message -- what is that resource?

Any ideas for further troubleshooting?

Thanks,

Allan

RE: problem with modify using python-ldap

[Howard C. <hy...@hi...>]

The "Resource Unavailable" message means a system call failed with errno =
EAGAIN. In this case, ldap_read was trying to read from the connection and
there was no data available. Sounds like the python library isn't flushing
the entire LDAP request out to the network.

The fact that the behavior changes with debug level set to 1 is disturbing.
It sounds like some kind of race condition is involved, because there should
not be any ldap_read's occurring between the modify completing and sending
its result. You didn't specify which version of RedHat Linux you're using,
but I'd guess you're on 7.0 or 7.1 with a buggy threads library.

  -- Howard Chu
  Chief Architect, Symas Corp.       Director, Highland Sun
  http://www.symas.com               http://highlandsun.com/hyc
  Symas: Premier OpenSource Development and Support

> -----Original Message-----
> From: own...@Op...
> [mailto:own...@Op...]On Behalf Of Allan Streib

> Using python-ldap-python-ldap-2.0.0pre04 with Python 2.2.1, and OpenLDAP
> 2.0.23 on RedHat Linux.
>
> Deleting and adding an attribute is taking 9 seconds.  The same actions
> using ldapmodify(1) on the command line complete virtually instantly.
>
> Oddly, the behavior does not manifest if log level 1 (trace function
> calls) is enabled.  Here is a log snip at level 6 (heavy trace debugging
> plus debug packet handling).  This first snip is with ldapmodify(1) as the
> client:
>
>     do_modify: dn (iuEduUPID=9900000004,ou=people,dc=iu,dc=edu)
>     modifications:
>             delete: iuEduMailDeliveryTo
>             add: iuEduMailDeliveryTo
>     ldbm_back_modify:
>     ldbm_modify_internal: delete
>     removing entire attribute iuEduMailDeliveryTo
>     ldbm_modify_internal: add
>     ldbm_modify_internal: replace
>     ldbm_modify_internal: replace
>     send_ldap_result: 0::
>
> Now with python-ldap's modify_s operation as the client:
>
>     do_modify: dn (iuEduUPID=9900000004,ou=people,dc=iu,dc=edu)
>     modifications:
>             delete: iuEduMailDeliveryTo
>             add: iuEduMailDeliveryTo
>     ldbm_back_modify:
>     ldbm_modify_internal: delete
>     removing entire attribute iuEduMailDeliveryTo
>     ldbm_modify_internal: add
>     ldbm_modify_internal: replace
>     ldbm_modify_internal: replace
>     ldap_read: want=1 error=Resource temporarily unavailable
>  **** hangs for about 9 seconds here ****
>     send_ldap_result: 0::
>
> Ultimately the modifications succeed.  The difference I see is that
> "Resource temporarily unavailable" message -- what is that resource?
>
> Any ideas for further troubleshooting?
>
> Thanks,
>
> Allan
>

RE: problem with modify using python-ldap

[Allan S. <as...@in...>]

On Wed, 22 May 2002, Howard Chu wrote:

> The "Resource Unavailable" message means a system call failed with errno
> = EAGAIN. In this case, ldap_read was trying to read from the connection
> and there was no data available. Sounds like the python library isn't
> flushing the entire LDAP request out to the network.
>
> The fact that the behavior changes with debug level set to 1 is
> disturbing.  It sounds like some kind of race condition is involved,
> because there should not be any ldap_read's occurring between the modify
> completing and sending its result. You didn't specify which version of
> RedHat Linux you're using, but I'd guess you're on 7.0 or 7.1 with a
> buggy threads library.

It is RedHat 7.2.  I am not seeing this anymore, the last hour or so.
Have not changed anything, but start and stop slapd a bunch of times with
different debugging levels.  It's back to my normal 256 at this time, and
everything is working.  ???

Allan

Re: problem with modify using python-ldap

[<mi...@st...>]

Howard Chu wrote:
 >>    do_modify: dn (iuEduUPID=9900000004,ou=people,dc=iu,dc=edu)
 >>    modifications:
 >>            delete: iuEduMailDeliveryTo
 >>            add: iuEduMailDeliveryTo
 >>    ldbm_back_modify:
 >>    ldbm_modify_internal: delete
 >>    removing entire attribute iuEduMailDeliveryTo
 >>    ldbm_modify_internal: add
 >>    ldbm_modify_internal: replace
 >>    ldbm_modify_internal: replace
 >>    ldap_read: want=1 error=Resource temporarily unavailable
 >> **** hangs for about 9 seconds here ****
 >>    send_ldap_result: 0::
 >
> The "Resource Unavailable" message means a system call failed with errno =
> EAGAIN. In this case, ldap_read was trying to read from the connection and
> there was no data available. Sounds like the python library isn't flushing
> the entire LDAP request out to the network.

Hmm, I have no clue why that happens. I've never had this problem 
except with some very strange LDAP servers like bigfoot's.

Howard, how to make sure the LDAP request is flushed?

Allan, if this problem occurs again can you post the relevant 
snippets of your Python code and can you also use trace_level=1 
when calling ldap.open() or ldap.initialize() which writes a trace 
log containing all the python-ldap API calls (maybe solely on 
python-ldap-dev).

Ciao, Michael.