LDAP Sync deactivates Users

joules · November 8, 2022, 5:13pm

Infos:

Used Zammad version: 5.2.3-1667896726.e5427da9.bullseye
Used Zammad installation type: package
Operating system: Debian 11
Browser + version: all

Expected behavior:

All Users that are present in LDAP remain “active” after a Sync

Actual behavior:

2 out of 1667 LDAP Users are being deactivated on every Sync

Steps to reproduce the behavior:

Perform an LDAP Sync. Either using the “Start new” button from the Integrations page, waiting for a scheduled ImportJob or running the ImportJob from the console (e.g. within the script that produces debug log ) all result in those same 2 accounts to get deactivated.

Additional Information

From searching the forum i understand that a user account in Zammad will get deactivated when the corresponding LDAP account is not returned by an LDAP query during the Sync.

I checked that by doing a simple ldapsearch from the command-line with the same ldap-host, bind-dn, base-dn, … as configured in Zammad. Here the LDAP accounts in question show up.
I ran the script suggested by Thorsten Eckel Ldap sync tcp errors - #2 by thorsteneckel and grep’ed through the debug log. Here the two LDAP accounts were missing. There was also no log indicating that the corresponding Zammad User accounts were deactivated (no idea if that is supposed to be in there though).

I compared the two accounts with accounts that are similar (customer accounts that were created at a similar time) which did not get deactivated in:

the ldapsearch results
the database backend of LDAP
zammad’s database

There is no apparent difference between ldapsearch results and ldap backend entries of active users and the two deactivated ones.
In the zammad database the only thing that caught my eye is the absence of the “!ruby/hash:ActiveSupport::HashWithIndifferentAccess” string in the preferences field.
It does not seem to be responsible though as it is also missing in the entries of some active users and removing it in a test environment does not cause the user to get deactivated on the next sync.

The production.log only contains notes about the ImportJob starting and completing as far as i can tell.
In the debug_issue.log i could not find any lines that contained either ldap uid or zammad uid or email addresses or names of the affected users.

It implies that ldap queries from ruby return incomplete results. I wonder why and if there is anything that could be done about it.

joules · November 15, 2022, 12:36pm

I collected some data to back up my observations above.
To do this i updated packages on both the production system and the test system to the same package-versions and deployed fresh database dumps from the production system of the customer-database in LDAP and the MySQL database for zammad.
I also synced zammad’s attachment storage on the filesystem.

In my original question i claimed that only 2 zammad accounts were affected.
The data below suggests that actually 112 accounts are affected judging from the difference in entries synced by an ImportJob and actual entries in the database.
My guess what happened to lead me to the impression that only 2 accounts were affected is that

only 2 users tried and failed to login to zammad after the sync problem first occured
those two users got re-activated by agents upon request
from then on only those two accounts appeared in zammad’s activity stream as being deactivated by the system (during an ldap sync).

Ldapsearch Comparison

Test System

(The grep 'dn:' is only to ommit empty lines produced by ldapsearch)

root@zammad-test:~# ldapsearch -D "cn=Manager,dc=company,dc=com" -LLL -W -H ldap://192.168.122.224 -s one -b "dc=company,dc=com" dn | grep 'dn:' | wc -l
Enter LDAP Password:
1670

The corresponding slapd log

Nov 15 11:49:19 ldap-test slapd[52426]: conn=1589 fd=11 ACCEPT from IP=192.168.122.225:45700 (IP=0.0.0.0:389)
Nov 15 11:49:19 ldap-test slapd[52426]: conn=1589 op=0 BIND dn="cn=Manager,dc=company,dc=com" method=128
Nov 15 11:49:19 ldap-test slapd[52426]: conn=1589 op=0 BIND dn="cn=Manager,dc=company,dc=com" mech=SIMPLE ssf=0
Nov 15 11:49:19 ldap-test slapd[52426]: conn=1589 op=0 RESULT tag=97 err=0 text=
Nov 15 11:49:19 ldap-test slapd[52426]: conn=1589 op=1 SRCH base="dc=company,dc=com" scope=1 deref=0 filter="(objectClass=*)"
Nov 15 11:49:19 ldap-test slapd[52426]: conn=1589 op=1 SRCH attr=dn
Nov 15 11:49:22 ldap-test slapd[52426]: conn=1589 op=1 SEARCH RESULT tag=101 err=0 nentries=1670 text=
Nov 15 11:49:22 ldap-test slapd[52426]: conn=1589 op=2 UNBIND
Nov 15 11:49:22 ldap-test slapd[52426]: conn=1589 fd=11 closed

Production System

root@zammad-production:~# ldapsearch -D "cn=Manager,dc=company,dc=com" -LLL -W -H ldap://192.168.122.224 -s one -b "dc=company,dc=com" dn | grep 'dn:' | wc -l
Enter LDAP Password:
1670

The corresponding slapd log

Nov 15 11:49:37 ldap-production slapd[902]: conn=1624 fd=11 ACCEPT from IP=192.168.122.225:40746 (IP=0.0.0.0:389)
Nov 15 11:49:37 ldap-production slapd[902]: conn=1624 op=0 BIND dn="cn=Manager,dc=company,dc=com" method=128
Nov 15 11:49:37 ldap-production slapd[902]: conn=1624 op=0 BIND dn="cn=Manager,dc=company,dc=com" mech=SIMPLE ssf=0
Nov 15 11:49:37 ldap-production slapd[902]: conn=1624 op=0 RESULT tag=97 err=0 text=
Nov 15 11:49:37 ldap-production slapd[902]: conn=1624 op=1 SRCH base="dc=company,dc=com" scope=1 deref=0 filter="(objectClass=*)"
Nov 15 11:49:37 ldap-production slapd[902]: conn=1624 op=1 SRCH attr=dn
Nov 15 11:49:45 ldap-production slapd[902]: conn=1624 op=1 SEARCH RESULT tag=101 err=0 nentries=1670 text=
Nov 15 11:49:45 ldap-production slapd[902]: conn=1624 op=2 UNBIND
Nov 15 11:49:45 ldap-production slapd[902]: conn=1624 fd=11 closed

LDAP Sync from the Integrations page

Test System

ldap-sync_test

(Don’t mind the 2 failed users. Those are test accounts with bogus email addresses)

journalctl -eu slapd.service

Nov 15 12:00:46 ldap-test slapd[52426]: conn=1590 fd=11 ACCEPT from IP=192.168.122.225:55882 (IP=0.0.0.0:389)
Nov 15 12:00:46 ldap-test slapd[52426]: conn=1590 op=0 BIND dn="cn=Manager,dc=company,dc=com" method=128
Nov 15 12:00:46 ldap-test slapd[52426]: conn=1590 op=0 BIND dn="cn=Manager,dc=company,dc=com" mech=SIMPLE ssf=0
Nov 15 12:00:46 ldap-test slapd[52426]: conn=1590 op=0 RESULT tag=97 err=0 text=
Nov 15 12:00:46 ldap-test slapd[52426]: conn=1590 fd=11 closed (connection lost)
Nov 15 12:00:46 ldap-test slapd[52426]: conn=1591 fd=11 ACCEPT from IP=192.168.122.225:55888 (IP=0.0.0.0:389)
Nov 15 12:00:46 ldap-test slapd[52426]: conn=1591 op=0 BIND dn="cn=Manager,dc=company,dc=com" method=128
Nov 15 12:00:46 ldap-test slapd[52426]: conn=1591 op=0 BIND dn="cn=Manager,dc=company,dc=com" mech=SIMPLE ssf=0
Nov 15 12:00:46 ldap-test slapd[52426]: conn=1591 op=0 RESULT tag=97 err=0 text=
Nov 15 12:00:46 ldap-test slapd[52426]: conn=1591 op=1 SRCH base="" scope=0 deref=0 filter="(objectClass=*)"
Nov 15 12:00:46 ldap-test slapd[52426]: conn=1591 op=1 SRCH attr=altServer namingContexts supportedCapabilities supportedControl supportedExtension supportedFeatures supportedLdapVersion supportedSASLMechanisms
Nov 15 12:00:46 ldap-test slapd[52426]: conn=1591 op=1 SEARCH RESULT tag=101 err=0 nentries=1 text=
Nov 15 12:00:46 ldap-test slapd[52426]: conn=1591 fd=11 closed (connection lost)
Nov 15 12:00:46 ldap-test slapd[52426]: conn=1592 fd=11 ACCEPT from IP=192.168.122.225:55896 (IP=0.0.0.0:389)
Nov 15 12:00:46 ldap-test slapd[52426]: conn=1592 op=0 BIND dn="cn=Manager,dc=company,dc=com" method=128
Nov 15 12:00:46 ldap-test slapd[52426]: conn=1592 op=0 BIND dn="cn=Manager,dc=company,dc=com" mech=SIMPLE ssf=0
Nov 15 12:00:46 ldap-test slapd[52426]: conn=1592 op=0 RESULT tag=97 err=0 text=
Nov 15 12:00:46 ldap-test slapd[52426]: conn=1592 op=1 SRCH base="dc=company,dc=com" scope=2 deref=0 filter="(objectClass=organization)"
Nov 15 12:00:46 ldap-test slapd[52426]: conn=1592 op=1 SRCH attr=dn member memberuid uniquemember
Nov 15 12:00:46 ldap-test slapd[52426]: conn=1592 op=1 SEARCH RESULT tag=101 err=0 nentries=1 text=
Nov 15 12:00:46 ldap-test slapd[52426]: conn=1592 fd=11 closed (connection lost)
Nov 15 12:00:46 ldap-test slapd[52426]: conn=1593 fd=11 ACCEPT from IP=192.168.122.225:55910 (IP=0.0.0.0:389)
Nov 15 12:00:46 ldap-test slapd[52426]: conn=1593 op=0 BIND dn="cn=Manager,dc=company,dc=com" method=128
Nov 15 12:00:46 ldap-test slapd[52426]: conn=1593 op=0 BIND dn="cn=Manager,dc=company,dc=com" mech=SIMPLE ssf=0
Nov 15 12:00:46 ldap-test slapd[52426]: conn=1593 op=0 RESULT tag=97 err=0 text=
Nov 15 12:00:46 ldap-test slapd[52426]: conn=1593 op=1 SRCH base="dc=company,dc=com" scope=2 deref=0 filter="(objectClass=person)"
Nov 15 12:00:46 ldap-test slapd[52426]: conn=1593 op=1 SRCH attr=givenname sn mail displayname telephonenumber dn uid
Nov 15 12:00:46 ldap-test slapd[52426]: conn=1593 op=1 SEARCH RESULT tag=101 err=0 nentries=126 text=
Nov 15 12:00:47 ldap-test slapd[52426]: conn=1593 op=2 SRCH base="dc=company,dc=com" scope=2 deref=0 filter="(objectClass=person)"
Nov 15 12:00:47 ldap-test slapd[52426]: conn=1593 op=2 SRCH attr=givenname sn mail displayname telephonenumber dn uid
Nov 15 12:00:47 ldap-test slapd[52426]: conn=1593 op=2 SEARCH RESULT tag=101 err=0 nentries=126 text=
Nov 15 12:00:49 ldap-test slapd[52426]: conn=1593 op=3 SRCH base="dc=company,dc=com" scope=2 deref=0 filter="(objectClass=person)"
Nov 15 12:00:49 ldap-test slapd[52426]: conn=1593 op=3 SRCH attr=givenname sn mail displayname telephonenumber dn uid
Nov 15 12:00:49 ldap-test slapd[52426]: conn=1593 op=3 SEARCH RESULT tag=101 err=0 nentries=126 text=
Nov 15 12:00:50 ldap-test slapd[52426]: conn=1593 op=4 SRCH base="dc=company,dc=com" scope=2 deref=0 filter="(objectClass=person)"
Nov 15 12:00:50 ldap-test slapd[52426]: conn=1593 op=4 SRCH attr=givenname sn mail displayname telephonenumber dn uid
Nov 15 12:00:51 ldap-test slapd[52426]: conn=1593 op=4 SEARCH RESULT tag=101 err=0 nentries=126 text=
Nov 15 12:00:52 ldap-test slapd[52426]: conn=1593 op=5 SRCH base="dc=company,dc=com" scope=2 deref=0 filter="(objectClass=person)"
Nov 15 12:00:52 ldap-test slapd[52426]: conn=1593 op=5 SRCH attr=givenname sn mail displayname telephonenumber dn uid
Nov 15 12:00:52 ldap-test slapd[52426]: conn=1593 op=5 SEARCH RESULT tag=101 err=0 nentries=126 text=
Nov 15 12:00:54 ldap-test slapd[52426]: conn=1593 op=6 SRCH base="dc=company,dc=com" scope=2 deref=0 filter="(objectClass=person)"
Nov 15 12:00:54 ldap-test slapd[52426]: conn=1593 op=6 SRCH attr=givenname sn mail displayname telephonenumber dn uid
Nov 15 12:00:54 ldap-test slapd[52426]: conn=1593 op=6 SEARCH RESULT tag=101 err=0 nentries=126 text=
Nov 15 12:00:55 ldap-test slapd[52426]: conn=1593 op=7 SRCH base="dc=company,dc=com" scope=2 deref=0 filter="(objectClass=person)"
Nov 15 12:00:55 ldap-test slapd[52426]: conn=1593 op=7 SRCH attr=givenname sn mail displayname telephonenumber dn uid
Nov 15 12:00:55 ldap-test slapd[52426]: conn=1593 op=7 SEARCH RESULT tag=101 err=0 nentries=126 text=
Nov 15 12:00:57 ldap-test slapd[52426]: conn=1593 op=8 SRCH base="dc=company,dc=com" scope=2 deref=0 filter="(objectClass=person)"
Nov 15 12:00:57 ldap-test slapd[52426]: conn=1593 op=8 SRCH attr=givenname sn mail displayname telephonenumber dn uid
Nov 15 12:00:57 ldap-test slapd[52426]: conn=1593 op=8 SEARCH RESULT tag=101 err=0 nentries=126 text=
Nov 15 12:00:58 ldap-test slapd[52426]: conn=1593 op=9 SRCH base="dc=company,dc=com" scope=2 deref=0 filter="(objectClass=person)"
Nov 15 12:00:58 ldap-test slapd[52426]: conn=1593 op=9 SRCH attr=givenname sn mail displayname telephonenumber dn uid
Nov 15 12:00:59 ldap-test slapd[52426]: conn=1593 op=9 SEARCH RESULT tag=101 err=0 nentries=126 text=
Nov 15 12:01:00 ldap-test slapd[52426]: conn=1593 op=10 SRCH base="dc=company,dc=com" scope=2 deref=0 filter="(objectClass=person)"
Nov 15 12:01:00 ldap-test slapd[52426]: conn=1593 op=10 SRCH attr=givenname sn mail displayname telephonenumber dn uid
Nov 15 12:01:00 ldap-test slapd[52426]: conn=1593 op=10 SEARCH RESULT tag=101 err=0 nentries=126 text=
Nov 15 12:01:02 ldap-test slapd[52426]: conn=1593 op=11 SRCH base="dc=company,dc=com" scope=2 deref=0 filter="(objectClass=person)"
Nov 15 12:01:02 ldap-test slapd[52426]: conn=1593 op=11 SRCH attr=givenname sn mail displayname telephonenumber dn uid
Nov 15 12:01:02 ldap-test slapd[52426]: conn=1593 op=11 SEARCH RESULT tag=101 err=0 nentries=126 text=
Nov 15 12:01:03 ldap-test slapd[52426]: conn=1593 op=12 SRCH base="dc=company,dc=com" scope=2 deref=0 filter="(objectClass=person)"
Nov 15 12:01:03 ldap-test slapd[52426]: conn=1593 op=12 SRCH attr=givenname sn mail displayname telephonenumber dn uid
Nov 15 12:01:03 ldap-test slapd[52426]: conn=1593 op=12 SEARCH RESULT tag=101 err=0 nentries=126 text=
Nov 15 12:01:05 ldap-test slapd[52426]: conn=1593 op=13 SRCH base="dc=company,dc=com" scope=2 deref=0 filter="(objectClass=person)"
Nov 15 12:01:05 ldap-test slapd[52426]: conn=1593 op=13 SRCH attr=givenname sn mail displayname telephonenumber dn uid
Nov 15 12:01:05 ldap-test slapd[52426]: conn=1593 op=13 SEARCH RESULT tag=101 err=0 nentries=126 text=
Nov 15 12:01:06 ldap-test slapd[52426]: conn=1593 op=14 SRCH base="dc=company,dc=com" scope=2 deref=0 filter="(objectClass=person)"
Nov 15 12:01:06 ldap-test slapd[52426]: conn=1593 op=14 SRCH attr=givenname sn mail displayname telephonenumber dn uid
Nov 15 12:01:06 ldap-test slapd[52426]: conn=1593 op=14 SEARCH RESULT tag=101 err=0 nentries=32 text=
Nov 15 12:01:07 ldap-test slapd[52426]: conn=1593 fd=11 closed (connection lost)

Note that the sum over the returned “nentries” in the SEARCH RESULTs when the search attributes are “givenname sn mail displayname telephonenumber dn uid” is exactly 1670.

Production System

ldap-sync_production

journalctl -eu slapd.service

Nov 15 12:00:46 ldap-production slapd[902]: conn=1628 op=0 BIND dn="cn=Manager,dc=company,dc=com" method=128
Nov 15 12:00:46 ldap-production slapd[902]: conn=1628 op=0 BIND dn="cn=Manager,dc=company,dc=com" mech=SIMPLE ssf=0
Nov 15 12:00:46 ldap-production slapd[902]: conn=1628 op=0 RESULT tag=97 err=0 text=
Nov 15 12:00:46 ldap-production slapd[902]: conn=1628 fd=11 closed (connection lost)
Nov 15 12:00:46 ldap-production slapd[902]: conn=1629 fd=11 ACCEPT from IP=192.168.122.225:44938 (IP=0.0.0.0:389)
Nov 15 12:00:46 ldap-production slapd[902]: conn=1629 op=0 BIND dn="cn=Manager,dc=company,dc=com" method=128
Nov 15 12:00:46 ldap-production slapd[902]: conn=1629 op=0 BIND dn="cn=Manager,dc=company,dc=com" mech=SIMPLE ssf=0
Nov 15 12:00:46 ldap-production slapd[902]: conn=1629 op=0 RESULT tag=97 err=0 text=
Nov 15 12:00:46 ldap-production slapd[902]: conn=1629 op=1 SRCH base="" scope=0 deref=0 filter="(objectClass=*)"
Nov 15 12:00:46 ldap-production slapd[902]: conn=1629 op=1 SRCH attr=altServer namingContexts supportedCapabilities supportedControl supportedExtension supportedFeatures supportedLdapVersion supportedSASLMechanisms
Nov 15 12:00:46 ldap-production slapd[902]: conn=1629 op=1 SEARCH RESULT tag=101 err=0 nentries=1 text=
Nov 15 12:00:46 ldap-production slapd[902]: conn=1629 fd=11 closed (connection lost)
Nov 15 12:00:46 ldap-production slapd[902]: conn=1630 fd=11 ACCEPT from IP=192.168.122.225:44952 (IP=0.0.0.0:389)
Nov 15 12:00:46 ldap-production slapd[902]: conn=1630 op=0 BIND dn="cn=Manager,dc=company,dc=com" method=128
Nov 15 12:00:46 ldap-production slapd[902]: conn=1630 op=0 BIND dn="cn=Manager,dc=company,dc=com" mech=SIMPLE ssf=0
Nov 15 12:00:46 ldap-production slapd[902]: conn=1630 op=0 RESULT tag=97 err=0 text=
Nov 15 12:00:46 ldap-production slapd[902]: conn=1630 op=1 SRCH base="dc=company,dc=com" scope=2 deref=0 filter="(objectClass=organization)"
Nov 15 12:00:46 ldap-production slapd[902]: conn=1630 op=1 SRCH attr=dn member memberuid uniquemember
Nov 15 12:00:46 ldap-production slapd[902]: conn=1630 op=1 SEARCH RESULT tag=101 err=0 nentries=1 text=
Nov 15 12:00:46 ldap-production slapd[902]: conn=1630 fd=11 closed (connection lost)
Nov 15 12:00:46 ldap-production slapd[902]: conn=1631 fd=11 ACCEPT from IP=192.168.122.225:44954 (IP=0.0.0.0:389)
Nov 15 12:00:46 ldap-production slapd[902]: conn=1631 op=0 BIND dn="cn=Manager,dc=company,dc=com" method=128
Nov 15 12:00:46 ldap-production slapd[902]: conn=1631 op=0 BIND dn="cn=Manager,dc=company,dc=com" mech=SIMPLE ssf=0
Nov 15 12:00:46 ldap-production slapd[902]: conn=1631 op=0 RESULT tag=97 err=0 text=
Nov 15 12:00:46 ldap-production slapd[902]: conn=1631 op=1 SRCH base="dc=company,dc=com" scope=2 deref=0 filter="(objectClass=person)"
Nov 15 12:00:46 ldap-production slapd[902]: conn=1631 op=1 SRCH attr=givenname sn mail displayname telephonenumber dn uid
Nov 15 12:00:46 ldap-production slapd[902]: conn=1631 op=1 SEARCH RESULT tag=101 err=0 nentries=126 text=
Nov 15 12:00:49 ldap-production slapd[902]: conn=1631 op=2 SRCH base="dc=company,dc=com" scope=2 deref=0 filter="(objectClass=person)"
Nov 15 12:00:49 ldap-production slapd[902]: conn=1631 op=2 SRCH attr=givenname sn mail displayname telephonenumber dn uid
Nov 15 12:00:50 ldap-production slapd[902]: conn=1631 op=2 SEARCH RESULT tag=101 err=0 nentries=126 text=
Nov 15 12:00:52 ldap-production slapd[902]: conn=1631 op=3 SRCH base="dc=company,dc=com" scope=2 deref=0 filter="(objectClass=person)"
Nov 15 12:00:52 ldap-production slapd[902]: conn=1631 op=3 SRCH attr=givenname sn mail displayname telephonenumber dn uid
Nov 15 12:00:53 ldap-production slapd[902]: conn=1631 op=3 SEARCH RESULT tag=101 err=0 nentries=126 text=
Nov 15 12:00:55 ldap-production slapd[902]: conn=1631 op=4 SRCH base="dc=company,dc=com" scope=2 deref=0 filter="(objectClass=person)"
Nov 15 12:00:55 ldap-production slapd[902]: conn=1631 op=4 SRCH attr=givenname sn mail displayname telephonenumber dn uid
Nov 15 12:00:56 ldap-production slapd[902]: conn=1631 op=4 SEARCH RESULT tag=101 err=0 nentries=126 text=
Nov 15 12:00:59 ldap-production slapd[902]: conn=1631 op=5 SRCH base="dc=company,dc=com" scope=2 deref=0 filter="(objectClass=person)"
Nov 15 12:00:59 ldap-production slapd[902]: conn=1631 op=5 SRCH attr=givenname sn mail displayname telephonenumber dn uid
Nov 15 12:00:59 ldap-production slapd[902]: conn=1631 op=5 SEARCH RESULT tag=101 err=0 nentries=126 text=
Nov 15 12:01:04 ldap-production slapd[902]: conn=1631 op=6 SRCH base="dc=company,dc=com" scope=2 deref=0 filter="(objectClass=person)"
Nov 15 12:01:04 ldap-production slapd[902]: conn=1631 op=6 SRCH attr=givenname sn mail displayname telephonenumber dn uid
Nov 15 12:01:05 ldap-production slapd[902]: conn=1631 op=6 SEARCH RESULT tag=101 err=0 nentries=126 text=
Nov 15 12:01:09 ldap-production slapd[902]: conn=1631 op=7 SRCH base="dc=company,dc=com" scope=2 deref=0 filter="(objectClass=person)"
Nov 15 12:01:09 ldap-production slapd[902]: conn=1631 op=7 SRCH attr=givenname sn mail displayname telephonenumber dn uid
Nov 15 12:01:10 ldap-production slapd[902]: conn=1631 op=7 SEARCH RESULT tag=101 err=0 nentries=126 text=
Nov 15 12:01:13 ldap-production slapd[902]: conn=1631 op=8 SRCH base="dc=company,dc=com" scope=2 deref=0 filter="(objectClass=person)"
Nov 15 12:01:13 ldap-production slapd[902]: conn=1631 op=8 SRCH attr=givenname sn mail displayname telephonenumber dn uid
Nov 15 12:01:14 ldap-production slapd[902]: conn=1631 op=8 SEARCH RESULT tag=101 err=0 nentries=126 text=
Nov 15 12:01:17 ldap-production slapd[902]: conn=1631 op=9 SRCH base="dc=company,dc=com" scope=2 deref=0 filter="(objectClass=person)"
Nov 15 12:01:17 ldap-production slapd[902]: conn=1631 op=9 SRCH attr=givenname sn mail displayname telephonenumber dn uid
Nov 15 12:01:18 ldap-production slapd[902]: conn=1631 op=9 SEARCH RESULT tag=101 err=0 nentries=126 text=
Nov 15 12:01:21 ldap-production slapd[902]: conn=1631 op=10 SRCH base="dc=company,dc=com" scope=2 deref=0 filter="(objectClass=person)"
Nov 15 12:01:21 ldap-production slapd[902]: conn=1631 op=10 SRCH attr=givenname sn mail displayname telephonenumber dn uid
Nov 15 12:01:22 ldap-production slapd[902]: conn=1631 op=10 SEARCH RESULT tag=101 err=0 nentries=126 text=
Nov 15 12:01:25 ldap-production slapd[902]: conn=1631 op=11 SRCH base="dc=company,dc=com" scope=2 deref=0 filter="(objectClass=person)"
Nov 15 12:01:25 ldap-production slapd[902]: conn=1631 op=11 SRCH attr=givenname sn mail displayname telephonenumber dn uid
Nov 15 12:01:26 ldap-production slapd[902]: conn=1631 op=11 SEARCH RESULT tag=101 err=0 nentries=126 text=
Nov 15 12:01:29 ldap-production slapd[902]: conn=1631 op=12 SRCH base="dc=company,dc=com" scope=2 deref=0 filter="(objectClass=person)"
Nov 15 12:01:29 ldap-production slapd[902]: conn=1631 op=12 SRCH attr=givenname sn mail displayname telephonenumber dn uid
Nov 15 12:01:30 ldap-production slapd[902]: conn=1631 op=12 SEARCH RESULT tag=101 err=0 nentries=126 text=
Nov 15 12:01:33 ldap-production slapd[902]: conn=1631 op=13 SRCH base="dc=company,dc=com" scope=2 deref=0 filter="(objectClass=person)"
Nov 15 12:01:33 ldap-production slapd[902]: conn=1631 op=13 SRCH attr=givenname sn mail displayname telephonenumber dn uid
Nov 15 12:01:33 ldap-production slapd[902]: conn=1631 op=13 SEARCH RESULT tag=101 err=0 nentries=46 text=
Nov 15 12:01:34 ldap-production slapd[902]: conn=1631 fd=11 closed (connection lost)

Note that the sum over the returned “nentries” in the SEARCH RESULTs when the search attributes are “givenname sn mail displayname telephonenumber dn uid” is 1558 which is not the number of useraccounts in the LDAP database (1670).

My conclusion is still that Zammad did not ask the LDAP for all users in the database.
I can’t tell if that is by design or if there is maybe a problem with ruby libraries or something else entirely.

When starting an ImportJob zammad is “calculating entries”.
Can maybe one of the developers tell me how this number of entries is calculated to give me a hint where to look for differences?

joules · November 15, 2022, 12:56pm

To rule out cacheing as the cause i re-activated two affected zammad users, performed a

$ zammad run rails r "Cache.clear"

on the production system and manually triggered an LDAP Sync via the Integrations page.
No difference.

Btw there is memcached running on both the test and production system.

casus · November 24, 2022, 1:48pm

Extending on this:
The issue escalated last week with roughly 70% of the users being deactivated during sync processes, reproducibly.
We were able to ascertain that the issue is connected to the result paging of ldap searches in conjunction with the net::ldap lib (not reproducing with e.g. ldapsearch). ldap backend is provided by slapd with no issues showing in the service logs.

Having seen this we were able to work around the issue by setting net::ldap to not use paging. This is done by patching zammad/lib/ldap.rb. In method “connection_params” we set:

params[:force_no_page] = true

This initializes the net::ldap connection to not use paging and solves the issue.

Please note that a similar issue came up earlier in Add possibility to authenticate via for LDAP sync · Issue #1422 · zammad/zammad · GitHub . That was fixed for that special case in Fixed issue #1442 - IBM bluepages searches fail. · zammad/zammad@0afcc33 · GitHub .

I’ll check if we can offer a more generic solution for this in a new dev category topic.

Update:
Added a solution proposal in the dev category.

system · March 24, 2023, 1:49pm

This topic was automatically closed 120 days after the last reply. New replies are no longer allowed.