[GH-ISSUE #245] Query performance is 3x slower than OpenLDAP #85

Closed
opened 2026-02-27 08:15:09 +03:00 by kerem · 8 comments
Owner

Originally created by @ikaruswill on GitHub (Jul 13, 2022).
Original GitHub issue: https://github.com/lldap/lldap/issues/245

Context

I've been keeping an eye on LLDAP for a long time as I'm quite done with LDAP tinkering. Really excited that it's now available on arm64.

My setup:

  • OpenLDAP on a Kubernetes cluster
  • ~10 apps leverage LDAP
  • Using ldap-user-manager as frontend
  • RFC2307BIS schema (very similar to LLDAP's current schema)

Test

So the test I decided to run was with Authelia comparing the 2 LDAP implementations.

Parameters

  • 3 logins in Authelia on OpenLDAP (averaged)
  • 3 logins in Authelia on LLDAP (averaged)
  • Test ran on arm64 nodes
  • Repeat on amd64 nodes (cursory)
  • All nodes run with Longhorn storage
    • With local replicas, meaning direct I/O, not through the network
  • All nodes run on Samsung 960 Evo+ M.2 SSDs
  • Both OpenLDAP and LLDAP are constrained to the following resources:
    resources:
      requests:
        memory: 20Mi
        cpu: 50m
      limits:
        memory: 100Mi
        cpu: 500m
    

Results

OpenLDAP

An Authelia login POST request takes ~1055ms.
With the following timestamped logs in OpenLDAP (timestamps from Kubernetes):

2022-07-13T04:15:33.630792773Z 62ce46e5 conn=16706 fd=12 ACCEPT from IP=10.42.0.73:49260 (IP=0.0.0.0:389)
2022-07-13T04:15:33.630919943Z 62ce46e5 conn=16706 op=0 BIND dn="cn=admin,dc=ikaruswill,dc=com" method=128
2022-07-13T04:15:33.631008028Z 62ce46e5 conn=16706 op=0 BIND dn="cn=admin,dc=ikaruswill,dc=com" mech=SIMPLE ssf=0
2022-07-13T04:15:33.631285118Z 62ce46e5 conn=16706 op=0 RESULT tag=97 err=0 text=
2022-07-13T04:15:33.632893406Z 62ce46e5 conn=16706 op=1 SRCH base="ou=people,dc=ikaruswill,dc=com" scope=2 deref=0 filter="(&(|(uid=ikaruswill)(mail=ikaruswill))(objectClass=inetOrgPerson))"
2022-07-13T04:15:33.633040992Z 62ce46e5 conn=16706 op=1 SRCH attr=uid mail givenName
2022-07-13T04:15:33.633895012Z 62ce46e5 conn=16706 op=1 SEARCH RESULT tag=101 err=0 nentries=1 text=
2022-07-13T04:15:33.676083623Z 62ce46e5 conn=16707 fd=14 ACCEPT from IP=10.42.0.73:49272 (IP=0.0.0.0:389)
2022-07-13T04:15:33.676183667Z 62ce46e5 conn=16707 op=0 BIND dn="uid=ikaruswill,ou=people,dc=ikaruswill,dc=com" method=128
2022-07-13T04:15:33.687025962Z 62ce46e5 conn=16707 op=0 BIND dn="uid=ikaruswill,ou=people,dc=ikaruswill,dc=com" mech=SIMPLE ssf=0
2022-07-13T04:15:33.687230509Z 62ce46e5 conn=16707 op=0 RESULT tag=97 err=0 text=
2022-07-13T04:15:33.689028092Z 62ce46e5 conn=16707 fd=14 closed (connection lost)
2022-07-13T04:15:33.689671441Z 62ce46e5 conn=16706 fd=12 closed (connection lost)
2022-07-13T04:15:33.882855246Z 62ce46e5 conn=16708 fd=12 ACCEPT from IP=10.42.0.73:49280 (IP=0.0.0.0:389)
2022-07-13T04:15:33.882979791Z 62ce46e5 conn=16708 op=0 BIND dn="cn=admin,dc=ikaruswill,dc=com" method=128
2022-07-13T04:15:33.883080126Z 62ce46e5 conn=16708 op=0 BIND dn="cn=admin,dc=ikaruswill,dc=com" mech=SIMPLE ssf=0
2022-07-13T04:15:33.883118044Z 62ce46e5 conn=16708 op=0 RESULT tag=97 err=0 text=
2022-07-13T04:15:33.885752230Z 62ce46e5 conn=16708 op=1 SRCH base="ou=people,dc=ikaruswill,dc=com" scope=2 deref=0 filter="(&(|(uid=ikaruswill)(mail=ikaruswill))(objectClass=inetOrgPerson))"
2022-07-13T04:15:33.885817857Z 62ce46e5 conn=16708 op=1 SRCH attr=uid mail givenName
2022-07-13T04:15:33.885831857Z 62ce46e5 conn=16708 op=1 SEARCH RESULT tag=101 err=0 nentries=1 text=
2022-07-13T04:15:33.886881882Z 62ce46e5 conn=16708 op=2 SRCH base="ou=groups,dc=ikaruswill,dc=com" scope=2 deref=0 filter="(&(uniqueMember=uid=ikaruswill,ou=people,dc=ikaruswill,dc=com)(objectClass=groupOfUniqueNames))"
2022-07-13T04:15:33.886937591Z 62ce46e5 conn=16708 op=2 SRCH attr=cn
2022-07-13T04:15:33.886951300Z 62ce46e5 <= mdb_equality_candidates: (uniqueMember) not indexed
2022-07-13T04:15:33.895780256Z 62ce46e5 conn=16708 op=2 SEARCH RESULT tag=101 err=0 nentries=8 text=
2022-07-13T04:15:33.970716049Z 62ce46e5 conn=16708 fd=12 closed (connection lost)

We can see that all operations complete in roughly 340ms

LLDAP

An Authelia login POST request takes ~1509ms.
With the following timestamped verbose logs in LLDAP (timestamps from LLDAP):

2022-07-13T04:29:00.816591486+00:00 INFO     LDAP session [ 463ms | 0.03% / 100.00% ]
2022-07-13T04:29:00.816889284+00:00 INFO     ┕━ LDAP request [ 463ms | 0.06% / 99.97% ]
2022-07-13T04:29:00.816910576+00:00 DEBUG       ┝━ 🐛 [debug]:  | msg: LdapMsg { msgid: 1, op: BindRequest(LdapBindRequest { dn: "uid=ikaruswill,ou=people,dc=example,dc=com", cred: Simple("********") }), ctrl: [] }
2022-07-13T04:29:00.816915826+00:00 DEBUG       ┝━ do_bind [ 463ms | 0.01% / 99.91% ]
2022-07-13T04:29:00.816920493+00:00 DEBUG       │  ┝━ 🐛 [debug]: DN: uid=ikaruswill,ou=people,dc=example,dc=com
2022-07-13T04:29:00.816932160+00:00 DEBUG       │  ┝━ bind [ 462ms | 0.03% / 99.85% ]
2022-07-13T04:29:00.817142165+00:00 DEBUG       │  │  ┕━ passwords_match [ 462ms | 99.82% ]
2022-07-13T04:29:01.279299461+00:00 DEBUG       │  ┝━ get_user_groups [ 243µs | 0.05% ]
2022-07-13T04:29:01.279318419+00:00 DEBUG       │  │  ┝━ 🐛 [debug]:  | user_id: UserId("ikaruswill")
2022-07-13T04:29:01.279381129+00:00 DEBUG       │  │  ┝━ 🐛 [debug]:  | query: SELECT "groups"."group_id", "display_name", "creation_date", "uuid" FROM "groups" INNER JOIN "memberships" ON "groups"."group_id" = "memberships"."group_id" WHERE "user_id" = ?
2022-07-13T04:29:01.280292317+00:00 DEBUG       │  │  ┕━ 🐛 [debug]:  | return: {}
2022-07-13T04:29:01.280313317+00:00 DEBUG       │  ┕━ 🐛 [debug]: Success!
2022-07-13T04:29:01.280336359+00:00 DEBUG       ┕━ 🐛 [debug]:  | response: BindResponse(LdapBindResponse { res: LdapResult { code: Success, matcheddn: "", message: "", referral: [] }, saslcreds: None })
2022-07-13T04:29:00.447588533+00:00 INFO     LDAP session [ 364ms | 0.06% / 100.00% ]
2022-07-13T04:29:00.447818079+00:00 INFO     ┝━ LDAP request [ 364ms | 0.07% / 99.77% ]
2022-07-13T04:29:00.447841705+00:00 DEBUG    │  ┝━ 🐛 [debug]:  | msg: LdapMsg { msgid: 1, op: BindRequest(LdapBindRequest { dn: "uid=admin,ou=people,dc=example,dc=com", cred: Simple("********") }), ctrl: [] }
2022-07-13T04:29:00.447846663+00:00 DEBUG    │  ┝━ do_bind [ 363ms | 0.01% / 99.71% ]
2022-07-13T04:29:00.447852205+00:00 DEBUG    │  │  ┝━ 🐛 [debug]: DN: uid=admin,ou=people,dc=example,dc=com
2022-07-13T04:29:00.447863289+00:00 DEBUG    │  │  ┝━ bind [ 363ms | 0.04% / 99.63% ]
2022-07-13T04:29:00.448150879+00:00 DEBUG    │  │  │  ┕━ passwords_match [ 363ms | 99.59% ]
2022-07-13T04:29:00.811100152+00:00 DEBUG    │  │  ┝━ get_user_groups [ 233µs | 0.06% ]
2022-07-13T04:29:00.811115610+00:00 DEBUG    │  │  │  ┝━ 🐛 [debug]:  | user_id: UserId("admin")
2022-07-13T04:29:00.811177445+00:00 DEBUG    │  │  │  ┝━ 🐛 [debug]:  | query: SELECT "groups"."group_id", "display_name", "creation_date", "uuid" FROM "groups" INNER JOIN "memberships" ON "groups"."group_id" = "memberships"."group_id" WHERE "user_id" = ?
2022-07-13T04:29:00.811557787+00:00 DEBUG    │  │  │  ┕━ 🐛 [debug]:  | return: {GroupDetails { group_id: GroupId(1), display_name: "lldap_admin", creation_date: 2022-07-12T23:48:25.516387433Z, uuid: Uuid("3dbc77b7-30bf-3bc9-9cbb-d59af658175a") }}
2022-07-13T04:29:00.811567412+00:00 DEBUG    │  │  ┕━ 🐛 [debug]: Success!
2022-07-13T04:29:00.811581121+00:00 DEBUG    │  ┕━ 🐛 [debug]:  | response: BindResponse(LdapBindResponse { res: LdapResult { code: Success, matcheddn: "", message: "", referral: [] }, saslcreds: None })
2022-07-13T04:29:00.812095341+00:00 INFO     ┕━ LDAP request [ 623µs | 0.07% / 0.17% ]
2022-07-13T04:29:00.812121300+00:00 DEBUG       ┝━ 🐛 [debug]:  | msg: LdapMsg { msgid: 2, op: SearchRequest(LdapSearchRequest { base: "ou=people,dc=example,dc=com", scope: Subtree, aliases: Never, sizelimit: 1, timelimit: 0, typesonly: false, filter: And([Or([Equality("uid", "ikaruswill"), Equality("mail", "ikaruswill")]), Equality("objectClass", "person")]), attrs: ["uid", "mail", "displayName"] }), ctrl: [] }
2022-07-13T04:29:00.812125092+00:00 DEBUG       ┝━ do_search [ 360µs | 0.01% / 0.10% ]
2022-07-13T04:29:00.812141425+00:00 DEBUG       │  ┝━ 🐛 [debug]:  | request.base: "ou=people,dc=example,dc=com" | scope: Users
2022-07-13T04:29:00.812144634+00:00 DEBUG       │  ┕━ get_user_list [ 334µs | 0.01% / 0.09% ]
2022-07-13T04:29:00.812153092+00:00 DEBUG       │     ┝━ 🐛 [debug]:  | ldap_filter: And([Or([Equality("uid", "ikaruswill"), Equality("mail", "ikaruswill")]), Equality("objectClass", "person")])
2022-07-13T04:29:00.812167384+00:00 DEBUG       │     ┝━ 🐛 [debug]:  | parsed_filters: And([Or([UserId(UserId("ikaruswill")), Equality("email", "ikaruswill")]), And([])])
2022-07-13T04:29:00.812169426+00:00 DEBUG       │     ┝━ expand_attribute_wildcards [ 14.3µs | 0.00% ]
2022-07-13T04:29:00.812181676+00:00 DEBUG       │     │  ┕━ 🐛 [debug]:  | ldap_attributes: ["uid", "mail", "displayName"] | resolved_attributes: ["uid", "mail", "displayName"]
2022-07-13T04:29:00.812191302+00:00 DEBUG       │     ┕━ list_users [ 268µs | 0.07% ]
2022-07-13T04:29:00.812199760+00:00 DEBUG       │        ┝━ 🐛 [debug]:  | filters: Some(And([Or([UserId(UserId("ikaruswill")), Equality("email", "ikaruswill")]), And([])])) | get_groups: false
2022-07-13T04:29:00.812269762+00:00 DEBUG       │        ┝━ 🐛 [debug]:  | query: SELECT "users"."user_id", "email", "users"."display_name", "first_name", "last_name", "avatar", "users"."creation_date", "users"."uuid" FROM "users" WHERE (("users"."user_id" = ?) OR (email = ?)) AND ? ORDER BY "users"."user_id" ASC
2022-07-13T04:29:00.812627645+00:00 DEBUG       │        ┕━ 🐛 [debug]:  | return: [UserAndGroups { user: User { user_id: UserId("ikaruswill"), email: "will@example.com", display_name: "Will", first_name: "Will", last_name: "Ho", creation_date: 2022-07-13T00:02:21.017041305Z, uuid: Uuid("7d80b567-0dfd-3f70-b4c9-53356c2c5c69") }, groups: None }]
2022-07-13T04:29:00.812667896+00:00 DEBUG       ┝━ 🐛 [debug]:  | response: SearchResultEntry(LdapSearchResultEntry { dn: "uid=ikaruswill,ou=people,dc=example,dc=com", attributes: [LdapPartialAttribute { atype: "uid", vals: ["ikaruswill"] }, LdapPartialAttribute { atype: "mail", vals: ["will@example.com"] }, LdapPartialAttribute { atype: "displayName", vals: ["Will"] }] })
2022-07-13T04:29:00.812820733+00:00 DEBUG       ┕━ 🐛 [debug]:  | response: SearchResultDone(LdapResult { code: Success, matcheddn: "", message: "", referral: [] })
2022-07-13T04:29:01.482971168+00:00 INFO     LDAP session [ 406ms | 0.07% / 100.00% ]
2022-07-13T04:29:01.483115838+00:00 INFO     ┝━ LDAP request [ 405ms | 0.07% / 99.66% ]
2022-07-13T04:29:01.483137130+00:00 DEBUG    │  ┝━ 🐛 [debug]:  | msg: LdapMsg { msgid: 1, op: BindRequest(LdapBindRequest { dn: "uid=admin,ou=people,dc=example,dc=com", cred: Simple("********") }), ctrl: [] }
2022-07-13T04:29:01.483141505+00:00 DEBUG    │  ┝━ do_bind [ 405ms | 0.01% / 99.59% ]
2022-07-13T04:29:01.483147047+00:00 DEBUG    │  │  ┝━ 🐛 [debug]: DN: uid=admin,ou=people,dc=example,dc=com
2022-07-13T04:29:01.483159589+00:00 DEBUG    │  │  ┝━ bind [ 404ms | 0.03% / 99.51% ]
2022-07-13T04:29:01.483448929+00:00 DEBUG    │  │  │  ┕━ passwords_match [ 404ms | 99.48% ]
2022-07-13T04:29:01.887600271+00:00 DEBUG    │  │  ┝━ get_user_groups [ 258µs | 0.06% ]
2022-07-13T04:29:01.887618063+00:00 DEBUG    │  │  │  ┝━ 🐛 [debug]:  | user_id: UserId("admin")
2022-07-13T04:29:01.887685439+00:00 DEBUG    │  │  │  ┝━ 🐛 [debug]:  | query: SELECT "groups"."group_id", "display_name", "creation_date", "uuid" FROM "groups" INNER JOIN "memberships" ON "groups"."group_id" = "memberships"."group_id" WHERE "user_id" = ?
2022-07-13T04:29:01.888157075+00:00 DEBUG    │  │  │  ┕━ 🐛 [debug]:  | return: {GroupDetails { group_id: GroupId(1), display_name: "lldap_admin", creation_date: 2022-07-12T23:48:25.516387433Z, uuid: Uuid("3dbc77b7-30bf-3bc9-9cbb-d59af658175a") }}
2022-07-13T04:29:01.888166992+00:00 DEBUG    │  │  ┕━ 🐛 [debug]: Success!
2022-07-13T04:29:01.888181284+00:00 DEBUG    │  ┕━ 🐛 [debug]:  | response: BindResponse(LdapBindResponse { res: LdapResult { code: Success, matcheddn: "", message: "", referral: [] }, saslcreds: None })
2022-07-13T04:29:01.888849508+00:00 INFO     ┝━ LDAP request [ 594µs | 0.07% / 0.15% ]
2022-07-13T04:29:01.888881008+00:00 DEBUG    │  ┝━ 🐛 [debug]:  | msg: LdapMsg { msgid: 2, op: SearchRequest(LdapSearchRequest { base: "ou=people,dc=example,dc=com", scope: Subtree, aliases: Never, sizelimit: 1, timelimit: 0, typesonly: false, filter: And([Or([Equality("uid", "ikaruswill"), Equality("mail", "ikaruswill")]), Equality("objectClass", "person")]), attrs: ["uid", "mail", "displayName"] }), ctrl: [] }
2022-07-13T04:29:01.888885675+00:00 DEBUG    │  ┝━ do_search [ 319µs | 0.01% / 0.08% ]
2022-07-13T04:29:01.888903175+00:00 DEBUG    │  │  ┝━ 🐛 [debug]:  | request.base: "ou=people,dc=example,dc=com" | scope: Users
2022-07-13T04:29:01.888906384+00:00 DEBUG    │  │  ┕━ get_user_list [ 288µs | 0.01% / 0.07% ]
2022-07-13T04:29:01.888915426+00:00 DEBUG    │  │     ┝━ 🐛 [debug]:  | ldap_filter: And([Or([Equality("uid", "ikaruswill"), Equality("mail", "ikaruswill")]), Equality("objectClass", "person")])
2022-07-13T04:29:01.888929718+00:00 DEBUG    │  │     ┝━ 🐛 [debug]:  | parsed_filters: And([Or([UserId(UserId("ikaruswill")), Equality("email", "ikaruswill")]), And([])])
2022-07-13T04:29:01.888931468+00:00 DEBUG    │  │     ┝━ expand_attribute_wildcards [ 14.9µs | 0.00% ]
2022-07-13T04:29:01.888943426+00:00 DEBUG    │  │     │  ┕━ 🐛 [debug]:  | ldap_attributes: ["uid", "mail", "displayName"] | resolved_attributes: ["uid", "mail", "displayName"]
2022-07-13T04:29:01.888953927+00:00 DEBUG    │  │     ┕━ list_users [ 221µs | 0.05% ]
2022-07-13T04:29:01.888962385+00:00 DEBUG    │  │        ┝━ 🐛 [debug]:  | filters: Some(And([Or([UserId(UserId("ikaruswill")), Equality("email", "ikaruswill")]), And([])])) | get_groups: false
2022-07-13T04:29:01.889033553+00:00 DEBUG    │  │        ┝━ 🐛 [debug]:  | query: SELECT "users"."user_id", "email", "users"."display_name", "first_name", "last_name", "avatar", "users"."creation_date", "users"."uuid" FROM "users" WHERE (("users"."user_id" = ?) OR (email = ?)) AND ? ORDER BY "users"."user_id" ASC
2022-07-13T04:29:01.889529690+00:00 DEBUG    │  │        ┕━ 🐛 [debug]:  | return: [UserAndGroups { user: User { user_id: UserId("ikaruswill"), email: "will@example.com", display_name: "Will", first_name: "Will", last_name: "Ho", creation_date: 2022-07-13T00:02:21.017041305Z, uuid: Uuid("7d80b567-0dfd-3f70-b4c9-53356c2c5c69") }, groups: None }]
2022-07-13T04:29:01.889566732+00:00 DEBUG    │  ┝━ 🐛 [debug]:  | response: SearchResultEntry(LdapSearchResultEntry { dn: "uid=ikaruswill,ou=people,dc=example,dc=com", attributes: [LdapPartialAttribute { atype: "uid", vals: ["ikaruswill"] }, LdapPartialAttribute { atype: "mail", vals: ["will@example.com"] }, LdapPartialAttribute { atype: "displayName", vals: ["Will"] }] })
2022-07-13T04:29:01.889723069+00:00 DEBUG    │  ┕━ 🐛 [debug]:  | response: SearchResultDone(LdapResult { code: Success, matcheddn: "", message: "", referral: [] })
2022-07-13T04:29:01.890699883+00:00 INFO     ┕━ LDAP request [ 485µs | 0.05% / 0.12% ]
2022-07-13T04:29:01.890732259+00:00 DEBUG       ┝━ 🐛 [debug]:  | msg: LdapMsg { msgid: 3, op: SearchRequest(LdapSearchRequest { base: "ou=groups,dc=example,dc=com", scope: Subtree, aliases: Never, sizelimit: 0, timelimit: 0, typesonly: false, filter: Equality("member", "uid=ikaruswill,ou=people,dc=example,dc=com"), attrs: ["cn"] }), ctrl: [] }
2022-07-13T04:29:01.890738676+00:00 DEBUG       ┝━ do_search [ 279µs | 0.01% / 0.07% ]
2022-07-13T04:29:01.890755593+00:00 DEBUG       │  ┝━ 🐛 [debug]:  | request.base: "ou=groups,dc=example,dc=com" | scope: Groups
2022-07-13T04:29:01.890759676+00:00 DEBUG       │  ┕━ get_groups_list [ 252µs | 0.01% / 0.06% ]
2022-07-13T04:29:01.890768718+00:00 DEBUG       │     ┝━ 🐛 [debug]:  | ldap_filter: Equality("member", "uid=ikaruswill,ou=people,dc=example,dc=com")
2022-07-13T04:29:01.890783885+00:00 DEBUG       │     ┝━ 🐛 [debug]:  | parsed_filters: Member(UserId("ikaruswill"))
2022-07-13T04:29:01.890787094+00:00 DEBUG       │     ┕━ list_groups [ 214µs | 0.05% ]
2022-07-13T04:29:01.890794094+00:00 DEBUG       │        ┝━ 🐛 [debug]:  | filters: Some(Member(UserId("ikaruswill")))
2022-07-13T04:29:01.890888304+00:00 DEBUG       │        ┝━ 🐛 [debug]:  | query: SELECT "groups"."group_id", "display_name", "creation_date", "uuid", "user_id" FROM "groups" LEFT JOIN "memberships" ON "groups"."group_id" = "memberships"."group_id" WHERE "memberships"."group_id" IN (SELECT "group_id" FROM "memberships" WHERE "user_id" = ?) ORDER BY "display_name" ASC, "user_id" ASC
2022-07-13T04:29:01.891471943+00:00 DEBUG       │        ┕━ 🐛 [debug]:  | return: []
2022-07-13T04:29:01.891498193+00:00 DEBUG       ┕━ 🐛 [debug]:  | response: SearchResultDone(LdapResult { code: Success, matcheddn: "", message: "", referral: [] })

We can see that all operations complete in roughly 1075ms

Summary

  • OpenLDAP
    • Request time for OpenLDAP is 1055ms
    • Total query time is 340ms
    • Other Authelia overheads is 715ms
  • LLDAP
    • Request time for LLDAP is 1549ms
    • Total query time is 1075ms
    • Other Authelia overheads is 474ms

Analysis

  • Authelia overheads slightly different in both, possibly due to log timestamp differences.
    • osixia/openldap does not output timestamps in logs, timestamps derived from kubectl log --timestamps
  • Overall Authelia login POST request is 1.5x slower in LLDAP than in OpenLDAP
  • Overall query time is 2.9x slower in LLDAP than OpenLDAP

Question

I understand that there is some performance difference to be expected since LDAP is indeed incredibly fast and we're switching to SQLite when using LLDAP.

Though I'm still curious whether this performance difference is expected?
Considering my user DB only has a single row, I'd imagine it should have been much faster.

If it is, is there anything that we can do to reduce this difference?

Notes and thoughts

  • I tried tracing the passwords_match code but I'm afraid I'm not well versed enough in rust to do so efficiently.
  • I looked at the SQLite DB and saw that the users table is already indexed by uid as the PRIMARY KEY. Not sure where else it could be slow here.
  • I tried a sqlite query on the users table by user_id in the container on the node itself and it was pretty fast. Thus I can confirm this delay is not bottlenecked by I/O.
    SELECT * from users where user_id = 'ikaruswill';
    ikaruswill|<redacted results>
    Run Time: real 0.000 user 0.000062 sys 0.000186
    
  • Perhaps the bottleneck is at password hash computation and comparison?
  • Edit: Updated test results due to some methodology flaw that exaggerated performance difference a little. Difference is still significant though.
Originally created by @ikaruswill on GitHub (Jul 13, 2022). Original GitHub issue: https://github.com/lldap/lldap/issues/245 ## Context I've been keeping an eye on LLDAP for a long time as I'm quite done with LDAP tinkering. Really excited that it's now available on `arm64`. My setup: * OpenLDAP on a Kubernetes cluster * ~10 apps leverage LDAP * Using `ldap-user-manager` as frontend * `RFC2307BIS` schema (very similar to LLDAP's current schema) ## Test So the test I decided to run was with Authelia comparing the 2 LDAP implementations. ### Parameters * 3 logins in Authelia on OpenLDAP (averaged) * 3 logins in Authelia on LLDAP (averaged) * Test ran on arm64 nodes * Repeat on amd64 nodes (cursory) * All nodes run with Longhorn storage * With local replicas, meaning direct I/O, not through the network * All nodes run on Samsung 960 Evo+ M.2 SSDs * Both OpenLDAP and LLDAP are constrained to the following resources: ``` resources: requests: memory: 20Mi cpu: 50m limits: memory: 100Mi cpu: 500m ``` ## Results ### OpenLDAP An Authelia login `POST` request takes ~1055ms. With the following timestamped logs in OpenLDAP (timestamps from Kubernetes): ``` 2022-07-13T04:15:33.630792773Z 62ce46e5 conn=16706 fd=12 ACCEPT from IP=10.42.0.73:49260 (IP=0.0.0.0:389) 2022-07-13T04:15:33.630919943Z 62ce46e5 conn=16706 op=0 BIND dn="cn=admin,dc=ikaruswill,dc=com" method=128 2022-07-13T04:15:33.631008028Z 62ce46e5 conn=16706 op=0 BIND dn="cn=admin,dc=ikaruswill,dc=com" mech=SIMPLE ssf=0 2022-07-13T04:15:33.631285118Z 62ce46e5 conn=16706 op=0 RESULT tag=97 err=0 text= 2022-07-13T04:15:33.632893406Z 62ce46e5 conn=16706 op=1 SRCH base="ou=people,dc=ikaruswill,dc=com" scope=2 deref=0 filter="(&(|(uid=ikaruswill)(mail=ikaruswill))(objectClass=inetOrgPerson))" 2022-07-13T04:15:33.633040992Z 62ce46e5 conn=16706 op=1 SRCH attr=uid mail givenName 2022-07-13T04:15:33.633895012Z 62ce46e5 conn=16706 op=1 SEARCH RESULT tag=101 err=0 nentries=1 text= 2022-07-13T04:15:33.676083623Z 62ce46e5 conn=16707 fd=14 ACCEPT from IP=10.42.0.73:49272 (IP=0.0.0.0:389) 2022-07-13T04:15:33.676183667Z 62ce46e5 conn=16707 op=0 BIND dn="uid=ikaruswill,ou=people,dc=ikaruswill,dc=com" method=128 2022-07-13T04:15:33.687025962Z 62ce46e5 conn=16707 op=0 BIND dn="uid=ikaruswill,ou=people,dc=ikaruswill,dc=com" mech=SIMPLE ssf=0 2022-07-13T04:15:33.687230509Z 62ce46e5 conn=16707 op=0 RESULT tag=97 err=0 text= 2022-07-13T04:15:33.689028092Z 62ce46e5 conn=16707 fd=14 closed (connection lost) 2022-07-13T04:15:33.689671441Z 62ce46e5 conn=16706 fd=12 closed (connection lost) 2022-07-13T04:15:33.882855246Z 62ce46e5 conn=16708 fd=12 ACCEPT from IP=10.42.0.73:49280 (IP=0.0.0.0:389) 2022-07-13T04:15:33.882979791Z 62ce46e5 conn=16708 op=0 BIND dn="cn=admin,dc=ikaruswill,dc=com" method=128 2022-07-13T04:15:33.883080126Z 62ce46e5 conn=16708 op=0 BIND dn="cn=admin,dc=ikaruswill,dc=com" mech=SIMPLE ssf=0 2022-07-13T04:15:33.883118044Z 62ce46e5 conn=16708 op=0 RESULT tag=97 err=0 text= 2022-07-13T04:15:33.885752230Z 62ce46e5 conn=16708 op=1 SRCH base="ou=people,dc=ikaruswill,dc=com" scope=2 deref=0 filter="(&(|(uid=ikaruswill)(mail=ikaruswill))(objectClass=inetOrgPerson))" 2022-07-13T04:15:33.885817857Z 62ce46e5 conn=16708 op=1 SRCH attr=uid mail givenName 2022-07-13T04:15:33.885831857Z 62ce46e5 conn=16708 op=1 SEARCH RESULT tag=101 err=0 nentries=1 text= 2022-07-13T04:15:33.886881882Z 62ce46e5 conn=16708 op=2 SRCH base="ou=groups,dc=ikaruswill,dc=com" scope=2 deref=0 filter="(&(uniqueMember=uid=ikaruswill,ou=people,dc=ikaruswill,dc=com)(objectClass=groupOfUniqueNames))" 2022-07-13T04:15:33.886937591Z 62ce46e5 conn=16708 op=2 SRCH attr=cn 2022-07-13T04:15:33.886951300Z 62ce46e5 <= mdb_equality_candidates: (uniqueMember) not indexed 2022-07-13T04:15:33.895780256Z 62ce46e5 conn=16708 op=2 SEARCH RESULT tag=101 err=0 nentries=8 text= 2022-07-13T04:15:33.970716049Z 62ce46e5 conn=16708 fd=12 closed (connection lost) ``` We can see that all operations complete in roughly 340ms ### LLDAP An Authelia login `POST` request takes ~1509ms. With the following timestamped verbose logs in LLDAP (timestamps from LLDAP): ``` 2022-07-13T04:29:00.816591486+00:00 INFO LDAP session [ 463ms | 0.03% / 100.00% ] 2022-07-13T04:29:00.816889284+00:00 INFO ┕━ LDAP request [ 463ms | 0.06% / 99.97% ] 2022-07-13T04:29:00.816910576+00:00 DEBUG ┝━ 🐛 [debug]: | msg: LdapMsg { msgid: 1, op: BindRequest(LdapBindRequest { dn: "uid=ikaruswill,ou=people,dc=example,dc=com", cred: Simple("********") }), ctrl: [] } 2022-07-13T04:29:00.816915826+00:00 DEBUG ┝━ do_bind [ 463ms | 0.01% / 99.91% ] 2022-07-13T04:29:00.816920493+00:00 DEBUG │ ┝━ 🐛 [debug]: DN: uid=ikaruswill,ou=people,dc=example,dc=com 2022-07-13T04:29:00.816932160+00:00 DEBUG │ ┝━ bind [ 462ms | 0.03% / 99.85% ] 2022-07-13T04:29:00.817142165+00:00 DEBUG │ │ ┕━ passwords_match [ 462ms | 99.82% ] 2022-07-13T04:29:01.279299461+00:00 DEBUG │ ┝━ get_user_groups [ 243µs | 0.05% ] 2022-07-13T04:29:01.279318419+00:00 DEBUG │ │ ┝━ 🐛 [debug]: | user_id: UserId("ikaruswill") 2022-07-13T04:29:01.279381129+00:00 DEBUG │ │ ┝━ 🐛 [debug]: | query: SELECT "groups"."group_id", "display_name", "creation_date", "uuid" FROM "groups" INNER JOIN "memberships" ON "groups"."group_id" = "memberships"."group_id" WHERE "user_id" = ? 2022-07-13T04:29:01.280292317+00:00 DEBUG │ │ ┕━ 🐛 [debug]: | return: {} 2022-07-13T04:29:01.280313317+00:00 DEBUG │ ┕━ 🐛 [debug]: Success! 2022-07-13T04:29:01.280336359+00:00 DEBUG ┕━ 🐛 [debug]: | response: BindResponse(LdapBindResponse { res: LdapResult { code: Success, matcheddn: "", message: "", referral: [] }, saslcreds: None }) 2022-07-13T04:29:00.447588533+00:00 INFO LDAP session [ 364ms | 0.06% / 100.00% ] 2022-07-13T04:29:00.447818079+00:00 INFO ┝━ LDAP request [ 364ms | 0.07% / 99.77% ] 2022-07-13T04:29:00.447841705+00:00 DEBUG │ ┝━ 🐛 [debug]: | msg: LdapMsg { msgid: 1, op: BindRequest(LdapBindRequest { dn: "uid=admin,ou=people,dc=example,dc=com", cred: Simple("********") }), ctrl: [] } 2022-07-13T04:29:00.447846663+00:00 DEBUG │ ┝━ do_bind [ 363ms | 0.01% / 99.71% ] 2022-07-13T04:29:00.447852205+00:00 DEBUG │ │ ┝━ 🐛 [debug]: DN: uid=admin,ou=people,dc=example,dc=com 2022-07-13T04:29:00.447863289+00:00 DEBUG │ │ ┝━ bind [ 363ms | 0.04% / 99.63% ] 2022-07-13T04:29:00.448150879+00:00 DEBUG │ │ │ ┕━ passwords_match [ 363ms | 99.59% ] 2022-07-13T04:29:00.811100152+00:00 DEBUG │ │ ┝━ get_user_groups [ 233µs | 0.06% ] 2022-07-13T04:29:00.811115610+00:00 DEBUG │ │ │ ┝━ 🐛 [debug]: | user_id: UserId("admin") 2022-07-13T04:29:00.811177445+00:00 DEBUG │ │ │ ┝━ 🐛 [debug]: | query: SELECT "groups"."group_id", "display_name", "creation_date", "uuid" FROM "groups" INNER JOIN "memberships" ON "groups"."group_id" = "memberships"."group_id" WHERE "user_id" = ? 2022-07-13T04:29:00.811557787+00:00 DEBUG │ │ │ ┕━ 🐛 [debug]: | return: {GroupDetails { group_id: GroupId(1), display_name: "lldap_admin", creation_date: 2022-07-12T23:48:25.516387433Z, uuid: Uuid("3dbc77b7-30bf-3bc9-9cbb-d59af658175a") }} 2022-07-13T04:29:00.811567412+00:00 DEBUG │ │ ┕━ 🐛 [debug]: Success! 2022-07-13T04:29:00.811581121+00:00 DEBUG │ ┕━ 🐛 [debug]: | response: BindResponse(LdapBindResponse { res: LdapResult { code: Success, matcheddn: "", message: "", referral: [] }, saslcreds: None }) 2022-07-13T04:29:00.812095341+00:00 INFO ┕━ LDAP request [ 623µs | 0.07% / 0.17% ] 2022-07-13T04:29:00.812121300+00:00 DEBUG ┝━ 🐛 [debug]: | msg: LdapMsg { msgid: 2, op: SearchRequest(LdapSearchRequest { base: "ou=people,dc=example,dc=com", scope: Subtree, aliases: Never, sizelimit: 1, timelimit: 0, typesonly: false, filter: And([Or([Equality("uid", "ikaruswill"), Equality("mail", "ikaruswill")]), Equality("objectClass", "person")]), attrs: ["uid", "mail", "displayName"] }), ctrl: [] } 2022-07-13T04:29:00.812125092+00:00 DEBUG ┝━ do_search [ 360µs | 0.01% / 0.10% ] 2022-07-13T04:29:00.812141425+00:00 DEBUG │ ┝━ 🐛 [debug]: | request.base: "ou=people,dc=example,dc=com" | scope: Users 2022-07-13T04:29:00.812144634+00:00 DEBUG │ ┕━ get_user_list [ 334µs | 0.01% / 0.09% ] 2022-07-13T04:29:00.812153092+00:00 DEBUG │ ┝━ 🐛 [debug]: | ldap_filter: And([Or([Equality("uid", "ikaruswill"), Equality("mail", "ikaruswill")]), Equality("objectClass", "person")]) 2022-07-13T04:29:00.812167384+00:00 DEBUG │ ┝━ 🐛 [debug]: | parsed_filters: And([Or([UserId(UserId("ikaruswill")), Equality("email", "ikaruswill")]), And([])]) 2022-07-13T04:29:00.812169426+00:00 DEBUG │ ┝━ expand_attribute_wildcards [ 14.3µs | 0.00% ] 2022-07-13T04:29:00.812181676+00:00 DEBUG │ │ ┕━ 🐛 [debug]: | ldap_attributes: ["uid", "mail", "displayName"] | resolved_attributes: ["uid", "mail", "displayName"] 2022-07-13T04:29:00.812191302+00:00 DEBUG │ ┕━ list_users [ 268µs | 0.07% ] 2022-07-13T04:29:00.812199760+00:00 DEBUG │ ┝━ 🐛 [debug]: | filters: Some(And([Or([UserId(UserId("ikaruswill")), Equality("email", "ikaruswill")]), And([])])) | get_groups: false 2022-07-13T04:29:00.812269762+00:00 DEBUG │ ┝━ 🐛 [debug]: | query: SELECT "users"."user_id", "email", "users"."display_name", "first_name", "last_name", "avatar", "users"."creation_date", "users"."uuid" FROM "users" WHERE (("users"."user_id" = ?) OR (email = ?)) AND ? ORDER BY "users"."user_id" ASC 2022-07-13T04:29:00.812627645+00:00 DEBUG │ ┕━ 🐛 [debug]: | return: [UserAndGroups { user: User { user_id: UserId("ikaruswill"), email: "will@example.com", display_name: "Will", first_name: "Will", last_name: "Ho", creation_date: 2022-07-13T00:02:21.017041305Z, uuid: Uuid("7d80b567-0dfd-3f70-b4c9-53356c2c5c69") }, groups: None }] 2022-07-13T04:29:00.812667896+00:00 DEBUG ┝━ 🐛 [debug]: | response: SearchResultEntry(LdapSearchResultEntry { dn: "uid=ikaruswill,ou=people,dc=example,dc=com", attributes: [LdapPartialAttribute { atype: "uid", vals: ["ikaruswill"] }, LdapPartialAttribute { atype: "mail", vals: ["will@example.com"] }, LdapPartialAttribute { atype: "displayName", vals: ["Will"] }] }) 2022-07-13T04:29:00.812820733+00:00 DEBUG ┕━ 🐛 [debug]: | response: SearchResultDone(LdapResult { code: Success, matcheddn: "", message: "", referral: [] }) 2022-07-13T04:29:01.482971168+00:00 INFO LDAP session [ 406ms | 0.07% / 100.00% ] 2022-07-13T04:29:01.483115838+00:00 INFO ┝━ LDAP request [ 405ms | 0.07% / 99.66% ] 2022-07-13T04:29:01.483137130+00:00 DEBUG │ ┝━ 🐛 [debug]: | msg: LdapMsg { msgid: 1, op: BindRequest(LdapBindRequest { dn: "uid=admin,ou=people,dc=example,dc=com", cred: Simple("********") }), ctrl: [] } 2022-07-13T04:29:01.483141505+00:00 DEBUG │ ┝━ do_bind [ 405ms | 0.01% / 99.59% ] 2022-07-13T04:29:01.483147047+00:00 DEBUG │ │ ┝━ 🐛 [debug]: DN: uid=admin,ou=people,dc=example,dc=com 2022-07-13T04:29:01.483159589+00:00 DEBUG │ │ ┝━ bind [ 404ms | 0.03% / 99.51% ] 2022-07-13T04:29:01.483448929+00:00 DEBUG │ │ │ ┕━ passwords_match [ 404ms | 99.48% ] 2022-07-13T04:29:01.887600271+00:00 DEBUG │ │ ┝━ get_user_groups [ 258µs | 0.06% ] 2022-07-13T04:29:01.887618063+00:00 DEBUG │ │ │ ┝━ 🐛 [debug]: | user_id: UserId("admin") 2022-07-13T04:29:01.887685439+00:00 DEBUG │ │ │ ┝━ 🐛 [debug]: | query: SELECT "groups"."group_id", "display_name", "creation_date", "uuid" FROM "groups" INNER JOIN "memberships" ON "groups"."group_id" = "memberships"."group_id" WHERE "user_id" = ? 2022-07-13T04:29:01.888157075+00:00 DEBUG │ │ │ ┕━ 🐛 [debug]: | return: {GroupDetails { group_id: GroupId(1), display_name: "lldap_admin", creation_date: 2022-07-12T23:48:25.516387433Z, uuid: Uuid("3dbc77b7-30bf-3bc9-9cbb-d59af658175a") }} 2022-07-13T04:29:01.888166992+00:00 DEBUG │ │ ┕━ 🐛 [debug]: Success! 2022-07-13T04:29:01.888181284+00:00 DEBUG │ ┕━ 🐛 [debug]: | response: BindResponse(LdapBindResponse { res: LdapResult { code: Success, matcheddn: "", message: "", referral: [] }, saslcreds: None }) 2022-07-13T04:29:01.888849508+00:00 INFO ┝━ LDAP request [ 594µs | 0.07% / 0.15% ] 2022-07-13T04:29:01.888881008+00:00 DEBUG │ ┝━ 🐛 [debug]: | msg: LdapMsg { msgid: 2, op: SearchRequest(LdapSearchRequest { base: "ou=people,dc=example,dc=com", scope: Subtree, aliases: Never, sizelimit: 1, timelimit: 0, typesonly: false, filter: And([Or([Equality("uid", "ikaruswill"), Equality("mail", "ikaruswill")]), Equality("objectClass", "person")]), attrs: ["uid", "mail", "displayName"] }), ctrl: [] } 2022-07-13T04:29:01.888885675+00:00 DEBUG │ ┝━ do_search [ 319µs | 0.01% / 0.08% ] 2022-07-13T04:29:01.888903175+00:00 DEBUG │ │ ┝━ 🐛 [debug]: | request.base: "ou=people,dc=example,dc=com" | scope: Users 2022-07-13T04:29:01.888906384+00:00 DEBUG │ │ ┕━ get_user_list [ 288µs | 0.01% / 0.07% ] 2022-07-13T04:29:01.888915426+00:00 DEBUG │ │ ┝━ 🐛 [debug]: | ldap_filter: And([Or([Equality("uid", "ikaruswill"), Equality("mail", "ikaruswill")]), Equality("objectClass", "person")]) 2022-07-13T04:29:01.888929718+00:00 DEBUG │ │ ┝━ 🐛 [debug]: | parsed_filters: And([Or([UserId(UserId("ikaruswill")), Equality("email", "ikaruswill")]), And([])]) 2022-07-13T04:29:01.888931468+00:00 DEBUG │ │ ┝━ expand_attribute_wildcards [ 14.9µs | 0.00% ] 2022-07-13T04:29:01.888943426+00:00 DEBUG │ │ │ ┕━ 🐛 [debug]: | ldap_attributes: ["uid", "mail", "displayName"] | resolved_attributes: ["uid", "mail", "displayName"] 2022-07-13T04:29:01.888953927+00:00 DEBUG │ │ ┕━ list_users [ 221µs | 0.05% ] 2022-07-13T04:29:01.888962385+00:00 DEBUG │ │ ┝━ 🐛 [debug]: | filters: Some(And([Or([UserId(UserId("ikaruswill")), Equality("email", "ikaruswill")]), And([])])) | get_groups: false 2022-07-13T04:29:01.889033553+00:00 DEBUG │ │ ┝━ 🐛 [debug]: | query: SELECT "users"."user_id", "email", "users"."display_name", "first_name", "last_name", "avatar", "users"."creation_date", "users"."uuid" FROM "users" WHERE (("users"."user_id" = ?) OR (email = ?)) AND ? ORDER BY "users"."user_id" ASC 2022-07-13T04:29:01.889529690+00:00 DEBUG │ │ ┕━ 🐛 [debug]: | return: [UserAndGroups { user: User { user_id: UserId("ikaruswill"), email: "will@example.com", display_name: "Will", first_name: "Will", last_name: "Ho", creation_date: 2022-07-13T00:02:21.017041305Z, uuid: Uuid("7d80b567-0dfd-3f70-b4c9-53356c2c5c69") }, groups: None }] 2022-07-13T04:29:01.889566732+00:00 DEBUG │ ┝━ 🐛 [debug]: | response: SearchResultEntry(LdapSearchResultEntry { dn: "uid=ikaruswill,ou=people,dc=example,dc=com", attributes: [LdapPartialAttribute { atype: "uid", vals: ["ikaruswill"] }, LdapPartialAttribute { atype: "mail", vals: ["will@example.com"] }, LdapPartialAttribute { atype: "displayName", vals: ["Will"] }] }) 2022-07-13T04:29:01.889723069+00:00 DEBUG │ ┕━ 🐛 [debug]: | response: SearchResultDone(LdapResult { code: Success, matcheddn: "", message: "", referral: [] }) 2022-07-13T04:29:01.890699883+00:00 INFO ┕━ LDAP request [ 485µs | 0.05% / 0.12% ] 2022-07-13T04:29:01.890732259+00:00 DEBUG ┝━ 🐛 [debug]: | msg: LdapMsg { msgid: 3, op: SearchRequest(LdapSearchRequest { base: "ou=groups,dc=example,dc=com", scope: Subtree, aliases: Never, sizelimit: 0, timelimit: 0, typesonly: false, filter: Equality("member", "uid=ikaruswill,ou=people,dc=example,dc=com"), attrs: ["cn"] }), ctrl: [] } 2022-07-13T04:29:01.890738676+00:00 DEBUG ┝━ do_search [ 279µs | 0.01% / 0.07% ] 2022-07-13T04:29:01.890755593+00:00 DEBUG │ ┝━ 🐛 [debug]: | request.base: "ou=groups,dc=example,dc=com" | scope: Groups 2022-07-13T04:29:01.890759676+00:00 DEBUG │ ┕━ get_groups_list [ 252µs | 0.01% / 0.06% ] 2022-07-13T04:29:01.890768718+00:00 DEBUG │ ┝━ 🐛 [debug]: | ldap_filter: Equality("member", "uid=ikaruswill,ou=people,dc=example,dc=com") 2022-07-13T04:29:01.890783885+00:00 DEBUG │ ┝━ 🐛 [debug]: | parsed_filters: Member(UserId("ikaruswill")) 2022-07-13T04:29:01.890787094+00:00 DEBUG │ ┕━ list_groups [ 214µs | 0.05% ] 2022-07-13T04:29:01.890794094+00:00 DEBUG │ ┝━ 🐛 [debug]: | filters: Some(Member(UserId("ikaruswill"))) 2022-07-13T04:29:01.890888304+00:00 DEBUG │ ┝━ 🐛 [debug]: | query: SELECT "groups"."group_id", "display_name", "creation_date", "uuid", "user_id" FROM "groups" LEFT JOIN "memberships" ON "groups"."group_id" = "memberships"."group_id" WHERE "memberships"."group_id" IN (SELECT "group_id" FROM "memberships" WHERE "user_id" = ?) ORDER BY "display_name" ASC, "user_id" ASC 2022-07-13T04:29:01.891471943+00:00 DEBUG │ ┕━ 🐛 [debug]: | return: [] 2022-07-13T04:29:01.891498193+00:00 DEBUG ┕━ 🐛 [debug]: | response: SearchResultDone(LdapResult { code: Success, matcheddn: "", message: "", referral: [] }) ``` We can see that all operations complete in roughly 1075ms ## Summary * OpenLDAP * Request time for OpenLDAP is 1055ms * Total query time is 340ms * Other Authelia overheads is 715ms * LLDAP * Request time for LLDAP is 1549ms * Total query time is 1075ms * Other Authelia overheads is 474ms ## Analysis * Authelia overheads slightly different in both, possibly due to log timestamp differences. * osixia/openldap does not output timestamps in logs, timestamps derived from `kubectl log --timestamps` * Overall Authelia login POST request is 1.5x slower in LLDAP than in OpenLDAP * Overall query time is 2.9x slower in LLDAP than OpenLDAP ## Question I understand that there is some performance difference to be expected since LDAP is indeed incredibly fast and we're switching to SQLite when using LLDAP. Though I'm still curious whether this performance difference is expected? Considering my user DB only has a single row, I'd imagine it should have been much faster. If it is, is there anything that we can do to reduce this difference? ## Notes and thoughts * I tried tracing the `passwords_match` code but I'm afraid I'm not well versed enough in rust to do so efficiently. * I looked at the SQLite DB and saw that the users table is already indexed by `uid` as the `PRIMARY KEY`. Not sure where else it could be slow here. * I tried a sqlite query on the `users` table by `user_id` in the container on the node itself and it was pretty fast. Thus I can confirm this delay is not bottlenecked by I/O. ``` SELECT * from users where user_id = 'ikaruswill'; ikaruswill|<redacted results> Run Time: real 0.000 user 0.000062 sys 0.000186 ``` * Perhaps the bottleneck is at password hash computation and comparison? * Edit: Updated test results due to some methodology flaw that exaggerated performance difference a little. Difference is still significant though.
kerem closed this issue 2026-02-27 08:15:10 +03:00
Author
Owner

@nitnelave commented on GitHub (Jul 13, 2022):

Wow, that's an extensive bug report :)

I could have saved you a lot of time if you had asked what of time :D This is a consequence of the login protocol we use: the web UI uses the OPAQUE protocol to avoid sending the user's password over the network, instead providing a zero knowledge proof that their password is correct. The safety of the protocol relies partly on an expensive hashing function (argon2 configured for multiple passes) to prevent practical brute force attacks if the DB leaks. The server has to compute a hash (and so does the client) so logging in is an expensive operation.

The situation is even slightly worse when logging in via LDAP since the client simply provides the plaintext password. The server then has to act as both sides of the opaque protocol to validate the password and has to do 2 independent hashes.

The hashes have been configured to be relatively fast (0.3-0.6s) in order to make logging in fast enough, but still expensive enough that brute force is not really an option (security by default).

If you bench any other LDAP query after logging in, you'll see that LLDAP is much faster than OpenLDAP (you saw ~800 us latency). You can also look at the timings in the verbose logs (verbose=true in the config) to see where the time was spent in a query.

<!-- gh-comment-id:1182814102 --> @nitnelave commented on GitHub (Jul 13, 2022): Wow, that's an extensive bug report :) I could have saved you a lot of time if you had asked what of time :D This is a consequence of the login protocol we use: the web UI uses the OPAQUE protocol to avoid sending the user's password over the network, instead providing a zero knowledge proof that their password is correct. The safety of the protocol relies partly on an expensive hashing function (argon2 configured for multiple passes) to prevent practical brute force attacks if the DB leaks. The server has to compute a hash (and so does the client) so logging in is an expensive operation. The situation is even slightly worse when logging in via LDAP since the client simply provides the plaintext password. The server then has to act as both sides of the opaque protocol to validate the password and has to do 2 independent hashes. The hashes have been configured to be relatively fast (0.3-0.6s) in order to make logging in fast enough, but still expensive enough that brute force is not really an option (security by default). If you bench any other LDAP query after logging in, you'll see that LLDAP is much faster than OpenLDAP (you saw ~800 us latency). You can also look at the timings in the verbose logs (verbose=true in the config) to see where the time was spent in a query.
Author
Owner

@ikaruswill commented on GitHub (Jul 13, 2022):

That's really cool. Thanks for taking the time as well to explain the architecture. Goes to show how much thought you've already invested in LLDAP. 👍

Based on what I understand, the server you mention here is non-LDAP-based, purely a rust backend, and the client here is also bundled together with the image, providing the LDAP interface and translating it to a query/format that the backend understands. Is that correct?

Then in LDAP, there's only a bare server, so passwords are in plain text in the LDAP query. The server then validates the password by comparing the hash from the query and from the data store. In the case of LDAP, perhaps the hash algorithm used (mine was crypt) is not as expensive as argon2 so there was some performance gains there at the expense of security and brute force enablement.

Overall, is it right to say I should probably increase CPU limits on LLDAP to help with login latency?

<!-- gh-comment-id:1182887057 --> @ikaruswill commented on GitHub (Jul 13, 2022): That's really cool. Thanks for taking the time as well to explain the architecture. Goes to show how much thought you've already invested in LLDAP. 👍 Based on what I understand, the server you mention here is non-LDAP-based, purely a rust backend, and the client here is also bundled together with the image, providing the LDAP interface and translating it to a query/format that the backend understands. Is that correct? Then in LDAP, there's only a bare server, so passwords are in plain text in the LDAP query. The server then validates the password by comparing the hash from the query and from the data store. In the case of LDAP, perhaps the hash algorithm used (mine was crypt) is not as expensive as argon2 so there was some performance gains there at the expense of security and brute force enablement. Overall, is it right to say I should probably increase CPU limits on LLDAP to help with login latency?
Author
Owner

@ikaruswill commented on GitHub (Jul 13, 2022):

Another question I have (out of curiosity) is if the client and server of LLDAP are doing the argon2 computation, and they're both in the container, and given that OpenLDAP does the 2 sides of the computation also in the container, the performance of logins should be comparable if they use the same algorithm right?

<!-- gh-comment-id:1182889186 --> @ikaruswill commented on GitHub (Jul 13, 2022): Another question I have (out of curiosity) is if the client and server of LLDAP are doing the argon2 computation, and they're both in the container, and given that OpenLDAP does the 2 sides of the computation also in the container, the performance of logins should be comparable if they use the same algorithm right?
Author
Owner

@ikaruswill commented on GitHub (Jul 13, 2022):

One sec, I noticed you mentioned logins through the web UI, I was using authelia so logins pass through directly to the LDAP port, not through the web UI. Does your explanation still apply?

<!-- gh-comment-id:1182891487 --> @ikaruswill commented on GitHub (Jul 13, 2022): One sec, I noticed you mentioned logins through the web UI, I was using authelia so logins pass through directly to the LDAP port, not through the web UI. Does your explanation still apply?
Author
Owner

@nitnelave commented on GitHub (Jul 13, 2022):

The OPAQUE protocol is doing more than just comparing hashes, but I guess in terms of expensive computation costs it's similar :)

The LLDAP server is basically:

  • an authentication server with OPAQUE login protocol
  • an GraphQL API server to serve data about users and groups
  • and an LDAP server that roughly maps to the two things above.

Most services will connect to LLDAP using the LDAP protocol, so it's "transparent" to them. Authelia sends the password in plain text using an LDAP login (bind) query to LLDAP. Then LLDAP has to do the two sides of the OPAQUE protocol, essentially doing both hashes (and yes they're more expensive than crypt). Compared to OpenLDAP with a similarly configured argon2 hash, LLDAP is still probably going to be ~2 times slower since it has to compute two hashes for a single login.

When logging in directly to the LLDAP administration web UI, your browser does one part of the protocol in JS (well, actually in WASM) and the server does the other half, so each computes a single hash and it's twice as fast.

I'm not sure you can really reduce the login latency, the hash algorithm is made to be slow, but you can try adding more CPU.

<!-- gh-comment-id:1182946517 --> @nitnelave commented on GitHub (Jul 13, 2022): The OPAQUE protocol is doing more than just comparing hashes, but I guess in terms of expensive computation costs it's similar :) The LLDAP server is basically: - an authentication server with OPAQUE login protocol - an GraphQL API server to serve data about users and groups - and an LDAP server that roughly maps to the two things above. Most services will connect to LLDAP using the LDAP protocol, so it's "transparent" to them. Authelia sends the password in plain text using an LDAP login (bind) query to LLDAP. Then LLDAP has to do the two sides of the OPAQUE protocol, essentially doing both hashes (and yes they're more expensive than `crypt`). Compared to OpenLDAP with a similarly configured `argon2` hash, LLDAP is still probably going to be ~2 times slower since it has to compute two hashes for a single login. When logging in directly to the LLDAP administration web UI, your browser does one part of the protocol in JS (well, actually in WASM) and the server does the other half, so each computes a single hash and it's twice as fast. I'm not sure you can really reduce the login latency, the hash algorithm is _made_ to be slow, but you can try adding more CPU.
Author
Owner

@ikaruswill commented on GitHub (Jul 13, 2022):

👍 Got it, thanks again for clarifying.

I increased the CPU limits, but I realized that adding more memory limit (from 20M to 50M) helps with the login much more than increasing CPU beyond 500m. Quite an interesting behaviour, thought to bring that to your attention since README.md mentioned requirements of <10MB.

Nonetheless, for anyone else who's keen, here's what I eventually settled at for a comparable login performance with OpenLDAP via the LDAP protocol:

resources:
  requests:
    memory: 20Mi
    cpu: 50m
  limits:
    memory: 100Mi
    cpu: 1000m

Will close this issue now since it's by design. Thanks a lot!

<!-- gh-comment-id:1183136974 --> @ikaruswill commented on GitHub (Jul 13, 2022): 👍 Got it, thanks again for clarifying. I increased the CPU limits, but I realized that adding more memory limit (from 20M to 50M) helps with the login much more than increasing CPU beyond 500m. Quite an interesting behaviour, thought to bring that to your attention since `README.md` mentioned requirements of `<10MB`. Nonetheless, for anyone else who's keen, here's what I eventually settled at for a comparable login performance with OpenLDAP via the LDAP protocol: ``` resources: requests: memory: 20Mi cpu: 50m limits: memory: 100Mi cpu: 1000m ``` Will close this issue now since it's by design. Thanks a lot!
Author
Owner

@nitnelave commented on GitHub (Jul 13, 2022):

Yeah, the argon2 hash algorithm is also hard on the RAM. From a simple benchmark loop (while true; do ldapsearch ...; done) I found that the memory usage goes up to 70MB. Less RAM will just make the login take longer, but it won't impact the rest of the performance.

<!-- gh-comment-id:1183181111 --> @nitnelave commented on GitHub (Jul 13, 2022): Yeah, the argon2 hash algorithm is also hard on the RAM. From a simple benchmark loop (`while true; do ldapsearch ...; done`) I found that the memory usage goes up to 70MB. Less RAM will just make the login take longer, but it won't impact the rest of the performance.
Author
Owner

@ikaruswill commented on GitHub (Jul 13, 2022):

That's indeed the same observation I had as well.

Less RAM higher latency for logins, all other operations remain the same. The 70MB number you gave is quite useful. Perhaps I'll set the limit a little higher to cater for the memory spikes and avoid the performance tradeoff associated with RAM bottlenecking.

Have a good one! Thanks for building LLDAP.

<!-- gh-comment-id:1183367848 --> @ikaruswill commented on GitHub (Jul 13, 2022): That's indeed the same observation I had as well. Less RAM higher latency for logins, all other operations remain the same. The 70MB number you gave is quite useful. Perhaps I'll set the limit a little higher to cater for the memory spikes and avoid the performance tradeoff associated with RAM bottlenecking. Have a good one! Thanks for building LLDAP.
Sign in to join this conversation.
No milestone
No project
No assignees
1 participant
Notifications
Due date
The due date is invalid or out of range. Please use the format "yyyy-mm-dd".

No due date set.

Dependencies

No dependencies set.

Reference
starred/lldap-lldap#85
No description provided.