LSWS 1.5 + LDAP : it works BUT....

Discussion in 'Bug Reports' started by bogus, Jul 5, 2004.

  1. bogus

    bogus New Member

    Hello,
    I'm back ! :D

    Well, LSWS now works with LDAP here but... it takes 2'30 to grant access ! Moreover, the results are not cached, so it takes another 2'30 each time... :cry:

    By the way, the same query made with ldapsearch takes less than 1 second !

    When I take a look at the logs, I see that LSWS retrieves the object attributes one by one, with a delay of exactly 8 seconds between each. Curious, isn't it ?

    LSWS LDAP conf :
    Realm Name
    SampleProtectedArea

    DB Type
    LDAP

    User DB Location
    ldap://myldap.com/dc=people,dc=myco,dc=net??sub?(uid=$k )

    User DB Max Cache Size
    200

    User DB Cache Timeout(secs)
    60

    Group DB Location
    N/A

    Group DB Max Cache Size
    200

    Group DB Cache Timeout(secs)
    60

    LDAP Bind DN
    uid=eos,o=myco,dc=people,dc=myco,dc=net


    LDAP Bind Password
    XXXXX

    ========> 2'30 (= 150 seconds)


    The ldapsearch command

    ldapsearch -x -h myldap.com -D "uid=eos,o=myco,dc=people,dc=myco,dc=net" -w XXXX -b dc=people,dc=myco,dc=net "(uid=niceuser)"

    =========> less than 1 second.


    Sincerely,

    Darned Nuisance
  2. mistwang

    mistwang LiteSpeed Staff

    Welcome back! :)

    Holy crap! :-(
    I setup a remote LDAP server across internet, the authentication speed is very fast!
    The delay is caused by openldap client library as all attributes are retrived inside a loop calling openldap API. You can try disable debug log or set log level to "medium", when log level set to "high", openldap library dumps a lot of debug information into stderr.log, that will cause a little delay, but I only see a couple milli-seconds delay in our log file.

    Also, you can try "tcpdump", see if there is any network activities during the delay, I bet there is no activity at all.

    If it does not take that long, the result should be cached.

    Best regards,
    George Wang
  3. bogus

    bogus New Member

    Hello,

    According to tcpdump, the LDAP query itself over the networks only takes a fraction of a second. All remaining 2'30 are happenning inside LSWS. And on each request.

    That's what LSWS log says too, by the way (first line), all the rest is offline :

    2004-07-06 12:02:49.207 [DEBUG] [127.0.0.1:33590-0] Received search result for request 3, found entries 1, references 0
    2004-07-06 12:02:49.207 [DEBUG] dn: uid=someone,o=mycorp,dc=people,dc=elikya,dc=net
    2004-07-06 12:02:49.207 [DEBUG] Attr carLicense:permis B
    2004-07-06 12:02:50.774 [DEBUG] Attr cn:Joe Bar
    2004-07-06 12:02:53.546 [DEBUG] Attr description:R'nD
    2004-07-06 12:02:56.801 [DEBUG] Attr displayName:J.Bar
    2004-07-06 12:03:00.563 [DEBUG] Attr objectClass:inetOrgPerson
    2004-07-06 12:03:00.563 [DEBUG] Attr objectClass:eek:rganizationalPerson
    2004-07-06 12:03:00.563 [DEBUG] Attr objectClass:person
    2004-07-06 12:03:00.563 [DEBUG] Attr objectClass:top
    2004-07-06 12:03:04.731 [DEBUG] Attr sn:Bar
    2004-07-06 12:03:09.306 [DEBUG] Attr uid:jbar
    2004-07-06 12:03:14.300 [DEBUG] Attr givenName:Joe
    2004-07-06 12:03:19.612 [DEBUG] Attr homePhone:0 299 45 67 89
    2004-07-06 12:03:25.320 [DEBUG] Attr homePostalAddress:20 rue des glands$39170 Brice
    2004-07-06 12:03:31.303 [DEBUG] Attr l:Brice
    2004-07-06 12:03:37.682 [DEBUG] Attr labeledURI:http://lab.mycorp.com
    2004-07-06 12:03:44.490 [DEBUG] Attr mail:lab@mycorp.com
    2004-07-06 12:03:52.222 [DEBUG] Attr o:MyCorp
    2004-07-06 12:03:59.393 [DEBUG] Attr ou:MyLab
    2004-07-06 12:04:06.761 [DEBUG] Attr postalAddress:80 avenue des buttes de Cogles$39700 Gruel
    2004-07-06 12:04:14.295 [DEBUG] Attr postalCode:39700
    2004-07-06 12:04:22.005 [DEBUG] Attr preferredLanguage:fr
    2004-07-06 12:04:29.891 [DEBUG] Attr st:FR
    2004-07-06 12:04:37.942 [DEBUG] Attr street:80 avenue des buttes de Cogles
    2004-07-06 12:04:46.344 [DEBUG] Attr telephoneNumber:0 299 789 987
    2004-07-06 12:04:54.615 [DEBUG] Attr title:Monsieur le chargé de recherches
    2004-07-06 12:05:02.930 [DEBUG] Attr userPassword:XX
    2004-07-06 12:05:11.289 [DEBUG] Attr businessCategory:Services
    2004-07-06 12:05:19.856 [DEBUG] Attr facsimileTelephoneNumber:0 223 123 456
    2004-07-06 12:05:19.944 [DEBUG] Search completed successfully.
    EEntries found: 1
    Search references returned: 0


    Sincerely,
  4. mistwang

    mistwang LiteSpeed Staff

    So, it exactly matches my analysis. The the delay is caused by Openldap client library! For debuging purpose, we enabled openldap LDAP and BER debug logging when the debug level of LSWS is set to "high", you can find tons of LDAP log entries in "lsws/logs/stderr.log".

    I have two suggestions:

    1. turn off LSWS debug logging, that will turn off Openldap debug logging as well, see how long is the delay, I bet the delay will dissappear. :roll:

    2. change User DB Location to
    Code:
    ldap://myldap.com/dc=people,dc=myco,dc=net?userPassword?sub?(uid=$k) 
    to only request "userPassword" attribute, as all the other attributes are uesless for authentication, if the delay still exists, it should be much shorter and the result should be cached.

    We probably will write our own asynchronize LDAP client code when we have time later.

    Best Regards,
    George Wang
  5. bogus

    bogus New Member

    You're right, disabling DEBUG works great !

    Thank you very much !

Share This Page