LDAP slow initial Sync

Infos:

  • Used Zammad version: 5.1.1-1650894976.28c5b986.bullseye
  • Used Zammad installation type: package
  • Operating system: Debian 11 (bullseye)
  • Browser + version: firefox.x86_64 91.7.0-3.el7.centos
  • Used MySQL version: 10.5.15-MariaDB-0+deb11u1
  • Used LDAP version: OpenLDAP 2.4.57+dfsg-3 (same version on zammad machine & remote server)

Expected behavior:

  • Initial LDAP sync completes in less than a few hours.

Actual behavior:

  • Initial LDAP sync takes >=20 hours.

Steps to reproduce the behavior:

  • Migrate Zammad (this required the recommended approach of doing major version updates and executing some rake commands but works!)
    • from source installation v3.3 on CentOS7 with accounts created via generic OAuth (and possibly other methods)
    • to package installation v5.1 on Debian11
  • Perform an initial LDAP sync on a system with ~9500 existing accounts and ~1500 accounts residing in LDAP (most of the LDAP accounts should match to existing zammad accounts).

System Specs (Test Environment):

  • 8 VCPUs
  • 16 GiB RAM
  • no swap (ruling out swap related issues)
  • qemu libvirt guest with a non-sparse qcow2 image as backing device (cache=writethrough)

Configurations & Logs:

  • Zammad
irb(main):001:0> ImportJob.last.attributes.except('payload').inspect
=> "{\"id\"=>15,
     \"name\"=>\"Import::Ldap\",
     \"dry_run\"=>false,
     \"result\"=>{
        \"skipped\"=>0,
        \"created\"=>163,
        \"updated\"=>1327,
        \"unchanged\"=>0,
        \"failed\"=>0,
        \"deactivated\"=>0,
        \"sum\"=>1490,
        \"total\"=>1565
     },
     \"started_at\"=>Thu, 28 Apr 2022 18:21:31 UTC +00:00,
     \"finished_at\"=>nil,
     \"created_at\"=>Thu, 28 Apr 2022 18:21:31 UTC +00:00,
     \"updated_at\"=>Fri, 29 Apr 2022 08:49:42 UTC +00:00
    }"

I tried increasing zammad’s performance with confiugration tips that i found on this forum:

$ zammad config:set ZAMMAD_SESSION_JOBS_CONCURRENT=4        # i didn't notice any difference
$ zammad config:set WEB_CONCURRENCY=4                       # i think the Webgui got a lot faster, but it had no impact on the LDAP Sync
$ zammad config:set MAX_THREADS=32                          # no difference (only 2 more than default afterall)
$ zammad config:set MIN_THREADS=8                           # no difference (only 3 more than default afterall)

$ mount -t tmpfs -o size=1g tmpfs /opt/zammad/tmp           # only 55M used 16h into the LDAP Sync
  • LDAP

Probably worth mentioning is that the LDAP Server uses the uncommon sql backend.
But the DIT design is incredibly simple and queriying & authentication works as expected from the zammad server.

dn: uid=<uid>,dc=<organization>,dc=com
objectClass: inetOrgPerson
cn: <firstname> <lastname>
sn: <lastname>
uid: <uid>
mail: <email>
givenName: <firstname>
userPassword:: <base64-encoded|PBKDF2-Password-Hash>

The corresponding logs from slapd. Timestamps of slapd are in UTC +0200 (so 20:21:31 corresponds to the ImportJob started at 18:21:31)

Apr 28 20:16:14 support-test systemd[1]: Starting LSB: OpenLDAP standalone server (Lightweight Directory Access Protocol)...
Apr 28 20:16:14 support-test slapd[167961]: @(#) $OpenLDAP: slapd 2.4.57+dfsg-3 (May 15 2021 23:03:34) $
                                                    Debian OpenLDAP Maintainers <pkg-openldap-devel@lists.alioth.debian.org>
Apr 28 20:16:14 support-test slapd[167962]: slapd starting
Apr 28 20:16:14 support-test slapd[167956]: Starting OpenLDAP: slapd.
Apr 28 20:16:14 support-test systemd[1]: Started LSB: OpenLDAP standalone server (Lightweight Directory Access Protocol).
Apr 28 20:21:13 support-test slapd[167962]: conn=1000 fd=11 ACCEPT from IP=192.168.122.225:43702 (IP=0.0.0.0:389)
Apr 28 20:21:13 support-test slapd[167962]: conn=1000 op=0 BIND dn="uid=1340,dc=<organization>,dc=com" method=128
Apr 28 20:21:13 support-test slapd[167962]: conn=1000 op=0 BIND dn="uid=1340,dc=<organization>,dc=com" mech=SIMPLE ssf=0
Apr 28 20:21:13 support-test slapd[167962]: conn=1000 op=0 RESULT tag=97 err=0 text=
Apr 28 20:21:13 support-test slapd[167962]: conn=1000 op=1 EXT oid=1.3.6.1.4.1.4203.1.11.3
Apr 28 20:21:13 support-test slapd[167962]: conn=1000 op=1 WHOAMI
Apr 28 20:21:13 support-test slapd[167962]: conn=1000 op=1 RESULT oid= err=0 text=
Apr 28 20:21:13 support-test slapd[167962]: conn=1000 op=2 UNBIND
Apr 28 20:21:13 support-test slapd[167962]: conn=1000 fd=11 closed
Apr 28 20:21:31 support-test slapd[167962]: conn=1001 fd=11 ACCEPT from IP=192.168.122.225:43704 (IP=0.0.0.0:389)
Apr 28 20:21:31 support-test slapd[167962]: conn=1001 op=0 BIND dn="cn=Manager,dc=<organization>,dc=com" method=128
Apr 28 20:21:31 support-test slapd[167962]: conn=1001 op=0 BIND dn="cn=Manager,dc=<organization>,dc=com" mech=SIMPLE ssf=0
Apr 28 20:21:31 support-test slapd[167962]: conn=1001 op=0 RESULT tag=97 err=0 text=
Apr 28 20:21:31 support-test slapd[167962]: conn=1001 fd=11 closed (connection lost)
Apr 28 20:21:31 support-test slapd[167962]: conn=1002 fd=11 ACCEPT from IP=192.168.122.225:43706 (IP=0.0.0.0:389)
Apr 28 20:21:31 support-test slapd[167962]: conn=1002 op=0 BIND dn="cn=Manager,dc=<organization>,dc=com" method=128
Apr 28 20:21:31 support-test slapd[167962]: conn=1002 op=0 BIND dn="cn=Manager,dc=<organization>,dc=com" mech=SIMPLE ssf=0
Apr 28 20:21:31 support-test slapd[167962]: conn=1002 op=0 RESULT tag=97 err=0 text=
Apr 28 20:21:31 support-test slapd[167962]: conn=1002 op=1 SRCH base="" scope=0 deref=0 filter="(objectClass=*)"
Apr 28 20:21:31 support-test slapd[167962]: conn=1002 op=1 SRCH attr=altServer namingContexts supportedCapabilities supportedControl supportedExtension supportedFeatures supportedLdapVersion supportedSASLMechanisms
Apr 28 20:21:31 support-test slapd[167962]: conn=1002 op=1 SEARCH RESULT tag=101 err=0 nentries=1 text=
Apr 28 20:21:31 support-test slapd[167962]: conn=1002 fd=11 closed (connection lost)
Apr 28 20:21:31 support-test slapd[167962]: conn=1003 fd=11 ACCEPT from IP=192.168.122.225:43708 (IP=0.0.0.0:389)
Apr 28 20:21:31 support-test slapd[167962]: conn=1003 op=0 BIND dn="cn=Manager,dc=<organization>,dc=com" method=128
Apr 28 20:21:31 support-test slapd[167962]: conn=1003 op=0 BIND dn="cn=Manager,dc=<organization>,dc=com" mech=SIMPLE ssf=0
Apr 28 20:21:31 support-test slapd[167962]: conn=1003 op=0 RESULT tag=97 err=0 text=
Apr 28 20:21:31 support-test slapd[167962]: conn=1003 op=1 SRCH base="dc=<organization>,dc=com" scope=2 deref=0 filter="(objectClass=organization)"
Apr 28 20:21:31 support-test slapd[167962]: conn=1003 op=1 SRCH attr=dn member memberuid uniquemember
Apr 28 20:21:31 support-test slapd[167962]: conn=1003 op=1 SEARCH RESULT tag=101 err=0 nentries=1 text=
Apr 28 20:21:31 support-test slapd[167962]: conn=1003 fd=11 closed (connection lost)
Apr 28 20:21:31 support-test slapd[167962]: conn=1004 fd=11 ACCEPT from IP=192.168.122.225:43710 (IP=0.0.0.0:389)
Apr 28 20:21:31 support-test slapd[167962]: conn=1004 op=0 BIND dn="cn=Manager,dc=<organization>,dc=com" method=128
Apr 28 20:21:31 support-test slapd[167962]: conn=1004 op=0 BIND dn="cn=Manager,dc=<organization>,dc=com" mech=SIMPLE ssf=0
Apr 28 20:21:31 support-test slapd[167962]: conn=1004 op=0 RESULT tag=97 err=0 text=
Apr 28 20:21:31 support-test slapd[167962]: conn=1004 op=1 SRCH base="dc=<organization>,dc=com" scope=2 deref=0 filter="(objectClass=person)"
Apr 28 20:21:31 support-test slapd[167962]: conn=1004 op=1 SEARCH RESULT tag=101 err=0 nentries=126 text=
Apr 28 20:21:31 support-test slapd[167962]: conn=1004 op=2 SRCH base="dc=<organization>,dc=com" scope=2 deref=0 filter="(objectClass=person)"
Apr 28 20:21:31 support-test slapd[167962]: conn=1004 op=2 SEARCH RESULT tag=101 err=0 nentries=126 text=
Apr 28 20:21:31 support-test slapd[167962]: conn=1004 op=3 SRCH base="dc=<organization>,dc=com" scope=2 deref=0 filter="(objectClass=person)"
Apr 28 20:21:31 support-test slapd[167962]: conn=1004 op=3 SEARCH RESULT tag=101 err=0 nentries=126 text=
Apr 28 20:21:31 support-test slapd[167962]: conn=1004 op=4 SRCH base="dc=<organization>,dc=com" scope=2 deref=0 filter="(objectClass=person)"
Apr 28 20:21:32 support-test slapd[167962]: conn=1004 op=4 SEARCH RESULT tag=101 err=0 nentries=126 text=
Apr 28 20:21:32 support-test slapd[167962]: conn=1004 op=5 SRCH base="dc=<organization>,dc=com" scope=2 deref=0 filter="(objectClass=person)"
Apr 28 20:21:32 support-test slapd[167962]: conn=1004 op=5 SEARCH RESULT tag=101 err=0 nentries=126 text=
Apr 28 20:21:32 support-test slapd[167962]: conn=1004 op=6 SRCH base="dc=<organization>,dc=com" scope=2 deref=0 filter="(objectClass=person)"
Apr 28 20:21:32 support-test slapd[167962]: conn=1004 op=6 SEARCH RESULT tag=101 err=0 nentries=126 text=
Apr 28 20:21:32 support-test slapd[167962]: conn=1004 op=7 SRCH base="dc=<organization>,dc=com" scope=2 deref=0 filter="(objectClass=person)"
Apr 28 20:21:32 support-test slapd[167962]: conn=1004 op=7 SEARCH RESULT tag=101 err=0 nentries=126 text=
Apr 28 20:21:32 support-test slapd[167962]: conn=1004 op=7 SEARCH RESULT tag=101 err=0 nentries=126 text=
Apr 28 20:21:32 support-test slapd[167962]: conn=1004 op=8 SRCH base="dc=<organization>,dc=com" scope=2 deref=0 filter="(objectClass=person)"
Apr 28 20:21:32 support-test slapd[167962]: conn=1004 op=8 SEARCH RESULT tag=101 err=0 nentries=126 text=
Apr 28 20:21:32 support-test slapd[167962]: conn=1004 op=9 SRCH base="dc=<organization>,dc=com" scope=2 deref=0 filter="(objectClass=person)"
Apr 28 20:21:33 support-test slapd[167962]: conn=1004 op=9 SEARCH RESULT tag=101 err=0 nentries=126 text=
Apr 28 20:21:33 support-test slapd[167962]: conn=1004 op=10 SRCH base="dc=<organization>,dc=com" scope=2 deref=0 filter="(objectClass=person)"
Apr 28 20:21:33 support-test slapd[167962]: conn=1004 op=10 SEARCH RESULT tag=101 err=0 nentries=126 text=
Apr 28 20:21:33 support-test slapd[167962]: conn=1004 op=11 SRCH base="dc=<organization>,dc=com" scope=2 deref=0 filter="(objectClass=person)"
Apr 28 20:21:33 support-test slapd[167962]: conn=1004 op=11 SEARCH RESULT tag=101 err=0 nentries=126 text=
Apr 28 20:21:33 support-test slapd[167962]: conn=1004 op=12 SRCH base="dc=<organization>,dc=com" scope=2 deref=0 filter="(objectClass=person)"
Apr 28 20:21:33 support-test slapd[167962]: conn=1004 op=12 SEARCH RESULT tag=101 err=0 nentries=126 text=
Apr 28 20:21:33 support-test slapd[167962]: conn=1004 op=13 SRCH base="dc=<organization>,dc=com" scope=2 deref=0 filter="(objectClass=person)"
Apr 28 20:21:33 support-test slapd[167962]: conn=1004 op=13 SEARCH RESULT tag=101 err=0 nentries=53 text=
Apr 28 20:21:33 support-test slapd[167962]: conn=1004 fd=11 closed (connection lost)
Apr 28 20:21:33 support-test slapd[167962]: conn=1005 fd=11 ACCEPT from IP=192.168.122.225:43712 (IP=0.0.0.0:389)
Apr 28 20:21:33 support-test slapd[167962]: conn=1005 op=0 BIND dn="cn=Manager,dc=<organization>,dc=com" method=128
Apr 28 20:21:33 support-test slapd[167962]: conn=1005 op=0 BIND dn="cn=Manager,dc=<organization>,dc=com" mech=SIMPLE ssf=0
Apr 28 20:21:33 support-test slapd[167962]: conn=1005 op=0 RESULT tag=97 err=0 text=
Apr 28 20:21:33 support-test slapd[167962]: conn=1005 op=1 SRCH base="dc=<organization>,dc=com" scope=2 deref=0 filter="(objectClass=person)"
Apr 28 20:21:33 support-test slapd[167962]: conn=1005 op=1 SRCH attr=givenname sn mail telephonenumber dn uid
Apr 28 20:21:34 support-test slapd[167962]: conn=1005 op=1 SEARCH RESULT tag=101 err=0 nentries=126 text=
Apr 28 20:21:37 support-test slapd[167962]: conn=1005 op=2 SRCH base="dc=<organization>,dc=com" scope=2 deref=0 filter="(objectClass=person)"
Apr 28 20:21:37 support-test slapd[167962]: conn=1005 op=2 SRCH attr=givenname sn mail telephonenumber dn uid
Apr 28 20:21:37 support-test slapd[167962]: conn=1005 op=2 SEARCH RESULT tag=101 err=0 nentries=126 text=
Apr 28 20:21:42 support-test slapd[167962]: conn=1005 op=3 SRCH base="dc=<organization>,dc=com" scope=2 deref=0 filter="(objectClass=person)"
Apr 28 20:21:42 support-test slapd[167962]: conn=1005 op=3 SRCH attr=givenname sn mail telephonenumber dn uid
Apr 28 20:21:42 support-test slapd[167962]: conn=1005 op=3 SEARCH RESULT tag=101 err=0 nentries=126 text=
Apr 28 20:21:48 support-test slapd[167962]: conn=1005 op=4 SRCH base="dc=<organization>,dc=com" scope=2 deref=0 filter="(objectClass=person)"
Apr 28 20:21:48 support-test slapd[167962]: conn=1005 op=4 SRCH attr=givenname sn mail telephonenumber dn uid
Apr 28 20:21:48 support-test slapd[167962]: conn=1005 op=4 SEARCH RESULT tag=101 err=0 nentries=126 text=
Apr 28 20:21:53 support-test slapd[167962]: conn=1005 op=5 SRCH base="dc=<organization>,dc=com" scope=2 deref=0 filter="(objectClass=person)"
Apr 28 20:21:53 support-test slapd[167962]: conn=1005 op=5 SRCH attr=givenname sn mail telephonenumber dn uid
Apr 28 20:21:53 support-test slapd[167962]: conn=1005 op=5 SEARCH RESULT tag=101 err=0 nentries=126 text=
Apr 28 20:21:59 support-test slapd[167962]: conn=1005 op=6 SRCH base="dc=<organization>,dc=com" scope=2 deref=0 filter="(objectClass=person)"
Apr 28 20:21:59 support-test slapd[167962]: conn=1005 op=6 SRCH attr=givenname sn mail telephonenumber dn uid
Apr 28 20:21:59 support-test slapd[167962]: conn=1005 op=6 SEARCH RESULT tag=101 err=0 nentries=126 text=
Apr 28 20:22:05 support-test slapd[167962]: conn=1005 op=7 SRCH base="dc=<organization>,dc=com" scope=2 deref=0 filter="(objectClass=person)"
Apr 28 20:22:05 support-test slapd[167962]: conn=1005 op=7 SRCH attr=givenname sn mail telephonenumber dn uid
Apr 28 20:22:05 support-test slapd[167962]: conn=1005 op=7 SEARCH RESULT tag=101 err=0 nentries=126 text=
Apr 28 20:22:12 support-test slapd[167962]: conn=1005 op=8 SRCH base="dc=<organization>,dc=com" scope=2 deref=0 filter="(objectClass=person)"
Apr 28 20:22:12 support-test slapd[167962]: conn=1005 op=8 SRCH attr=givenname sn mail telephonenumber dn uid
Apr 28 20:22:12 support-test slapd[167962]: conn=1005 op=8 SEARCH RESULT tag=101 err=0 nentries=126 text=
Apr 28 20:22:18 support-test slapd[167962]: conn=1005 op=9 SRCH base="dc=<organization>,dc=com" scope=2 deref=0 filter="(objectClass=person)"
Apr 28 20:22:18 support-test slapd[167962]: conn=1005 op=9 SRCH attr=givenname sn mail telephonenumber dn uid
Apr 28 20:22:18 support-test slapd[167962]: conn=1005 op=9 SEARCH RESULT tag=101 err=0 nentries=126 text=
Apr 28 20:22:24 support-test slapd[167962]: conn=1005 op=10 SRCH base="dc=<organization>,dc=com" scope=2 deref=0 filter="(objectClass=person)"
Apr 28 20:22:24 support-test slapd[167962]: conn=1005 op=10 SRCH attr=givenname sn mail telephonenumber dn uid
Apr 28 20:22:24 support-test slapd[167962]: conn=1005 op=10 SEARCH RESULT tag=101 err=0 nentries=126 text=
Apr 28 20:22:30 support-test slapd[167962]: conn=1005 op=11 SRCH base="dc=<organization>,dc=com" scope=2 deref=0 filter="(objectClass=person)"
Apr 28 20:22:30 support-test slapd[167962]: conn=1005 op=11 SRCH attr=givenname sn mail telephonenumber dn uid
Apr 28 20:22:30 support-test slapd[167962]: conn=1005 op=11 SEARCH RESULT tag=101 err=0 nentries=126 text=
Apr 29 03:49:22 support-test slapd[167962]: conn=1005 op=12 SRCH base="dc=<organization>,dc=com" scope=2 deref=0 filter="(objectClass=person)"
Apr 29 03:49:22 support-test slapd[167962]: conn=1005 op=12 SRCH attr=givenname sn mail telephonenumber dn uid
Apr 29 03:49:23 support-test slapd[167962]: conn=1005 op=12 SEARCH RESULT tag=101 err=0 nentries=126 text=
Apr 29 11:57:03 support-test slapd[167962]: conn=1006 fd=14 ACCEPT from IP=192.168.122.225:54728 (IP=0.0.0.0:389)                                       # this corresponds to a manual ldapsearch => fails
Apr 29 11:57:03 support-test slapd[167962]: conn=1006 op=0 BIND dn="cn=Manager,dc=<organization>,dc=com" method=128
Apr 29 11:57:03 support-test slapd[167962]: conn=1006 op=0 BIND dn="cn=Manager,dc=<organization>,dc=com" mech=SIMPLE ssf=0
Apr 29 11:57:03 support-test slapd[167962]: conn=1006 op=0 RESULT tag=97 err=0 text=
Apr 29 11:57:03 support-test slapd[167962]: conn=1006 op=1 SRCH base="dc=<organization>,dc=com" scope=1 deref=0 filter="(objectClass=*)"
Apr 29 11:57:03 support-test slapd[167962]: conn=1006 op=1 SEARCH RESULT tag=101 err=80 nentries=0 text=
Apr 29 11:57:03 support-test slapd[167962]: conn=1006 op=2 UNBIND
Apr 29 11:57:03 support-test slapd[167962]: conn=1006 fd=14 closed
Apr 29 11:59:24 support-test systemd[1]: Stopping LSB: OpenLDAP standalone server (Lightweight Directory Access Protocol)...                            # restarting slapd
Apr 29 11:59:24 support-test slapd[167962]: daemon: shutdown requested and initiated.
Apr 29 11:59:24 support-test slapd[167962]: conn=1005 fd=11 closed (slapd shutdown)
Apr 29 11:59:24 support-test slapd[167962]: slapd shutdown: waiting for 0 operations/tasks to finish
Apr 29 11:59:24 support-test slapd[167962]: DIGEST-MD5 common mech free
Apr 29 11:59:24 support-test slapd[167962]: DIGEST-MD5 common mech free
Apr 29 11:59:24 support-test slapd[167962]: slapd stopped.
Apr 29 11:59:24 support-test slapd[172203]: Stopping OpenLDAP: slapd.
Apr 29 11:59:24 support-test systemd[1]: slapd.service: Succeeded.
Apr 29 11:59:24 support-test systemd[1]: Stopped LSB: OpenLDAP standalone server (Lightweight Directory Access Protocol).
Apr 29 11:59:24 support-test systemd[1]: slapd.service: Consumed 1.901s CPU time.
Apr 29 11:59:24 support-test systemd[1]: Starting LSB: OpenLDAP standalone server (Lightweight Directory Access Protocol)...
Apr 29 11:59:24 support-test slapd[172213]: @(#) $OpenLDAP: slapd 2.4.57+dfsg-3 (May 15 2021 23:03:34) $
                                                    Debian OpenLDAP Maintainers <pkg-openldap-devel@lists.alioth.debian.org>
Apr 29 11:59:24 support-test slapd[172214]: slapd starting
Apr 29 11:59:24 support-test slapd[172208]: Starting OpenLDAP: slapd.
Apr 29 11:59:24 support-test systemd[1]: Started LSB: OpenLDAP standalone server (Lightweight Directory Access Protocol).
Apr 29 11:59:28 support-test slapd[172214]: conn=1000 fd=11 ACCEPT from IP=192.168.122.225:54786 (IP=0.0.0.0:389)                                       # repeating the manual ldapsearch => succeeds
Apr 29 11:59:28 support-test slapd[172214]: conn=1000 op=0 BIND dn="cn=Manager,dc=<organization>,dc=com" method=128
Apr 29 11:59:28 support-test slapd[172214]: conn=1000 op=0 BIND dn="cn=Manager,dc=<organization>,dc=com" mech=SIMPLE ssf=0
Apr 29 11:59:28 support-test slapd[172214]: conn=1000 op=0 RESULT tag=97 err=0 text=
Apr 29 11:59:28 support-test slapd[172214]: conn=1000 op=1 SRCH base="dc=<organization>,dc=com" scope=1 deref=0 filter="(objectClass=*)"
Apr 29 11:59:30 support-test slapd[172214]: conn=1000 op=1 SEARCH RESULT tag=101 err=0 nentries=1565 text=
Apr 29 11:59:30 support-test slapd[172214]: conn=1000 op=2 UNBIND
Apr 29 11:59:30 support-test slapd[172214]: conn=1000 fd=11 closed
  • MariaDB

htop shows 2 mariadb threads running on 100% CPU the whole time. ps’s output looks different but my point is, that zammad seems to be using 1 mysql connection which maxes out 1 VCPU while 7 VCPUs are almost idle and multiple available mariadb threads are sleeping. I understand that multi-threading with mariadb is generally not a simple topic and changing it can have a negative performance impact during normal operation (as opposed to thousands of INSERTs like here).

root@tickets-test:~# ps -u mysql um
USER         PID %CPU %MEM    VSZ   RSS TTY      STAT START   TIME COMMAND
mysql      22192 73.1 10.3 15732848 1702648 ?    -    Apr27 1875:44 /usr/sbin/mariadbd
mysql          -  0.0    -      -     - -        Ssl  Apr27   0:00 -
mysql          -  0.0    -      -     - -        Ssl  Apr27   0:28 -
mysql          -  0.0    -      -     - -        Ssl  Apr27   0:00 -
mysql          -  0.0    -      -     - -        Ssl  Apr27   0:00 -
mysql          -  0.0    -      -     - -        Ssl  Apr27   0:00 -
mysql          -  0.0    -      -     - -        Ssl  Apr27   0:00 -
mysql          -  0.0    -      -     - -        Ssl  Apr27   0:00 -
mysql          -  0.0    -      -     - -        Ssl  Apr27   0:10 -
mysql          -  0.0    -      -     - -        Ssl  Apr27   0:07 -
mysql          -  0.0    -      -     - -        Ssl  Apr27   0:31 -
mysql          -  0.0    -      -     - -        Ssl  Apr27   0:14 -
mysql          -  0.0    -      -     - -        Ssl  Apr27   0:01 -
mysql          -  0.0    -      -     - -        Ssl  Apr27   0:00 -
mysql          -  0.0    -      -     - -        Ssl  Apr27   0:00 -
mysql          -  0.0    -      -     - -        Ssl  Apr27   0:41 -
mysql          - 36.1    -      -     - -        Rsl  Apr27 925:04 -
mysql          -  0.0    -      -     - -        Ssl  Apr27   0:25 -
mysql          -  0.0    -      -     - -        Ssl  Apr28   0:00 -
mysql          -  0.0    -      -     - -        Ssl  Apr28   0:04 -
mysql          -  0.0    -      -     - -        Ssl  Apr28   0:11 -
mysql          -  0.0    -      -     - -        Ssl  Apr28   0:00 -
mysql          -  0.0    -      -     - -        Ssl  01:04   0:00 -
mysql          -  0.0    -      -     - -        Ssl  10:23   0:00 -
mysql          -  0.0    -      -     - -        Ssl  10:52   0:00 -
mysql          -  0.0    -      -     - -        Ssl  10:52   0:00 -
mysql          -  0.0    -      -     - -        Ssl  10:53   0:00 -
mysql          -  0.0    -      -     - -        Ssl  11:42   0:00 -
mysql          -  0.0    -      -     - -        Ssl  11:42   0:00 -
mysql          -  0.0    -      -     - -        Ssl  11:44   0:00 -
mysql          -  0.0    -      -     - -        Ssl  11:44   0:00 -
mysql          -  0.0    -      -     - -        Ssl  11:44   0:00 -
mysql          -  0.0    -      -     - -        Ssl  11:44   0:00 -
mysql          -  0.0    -      -     - -        Ssl  11:46   0:00 -
mysql          -  0.0    -      -     - -        Ssl  11:46   0:00 -
mysql          -  0.0    -      -     - -        Ssl  11:46   0:00 -
root@tickets-test:~# mysqladmin proc stat
+------+--------+-----------+--------+---------+-------+--------------+------------------------------------------------------------------------------------------------------+----------+
| Id   | User   | Host      | db     | Command | Time  | State        | Info                                                                                                 | Progress |
+------+--------+-----------+--------+---------+-------+--------------+------------------------------------------------------------------------------------------------------+----------+
| 6172 | zammad | localhost | zammad | Sleep   | 9     |              |                                                                                                      | 0.000    |
| 6173 | zammad | localhost | zammad | Sleep   | 7     |              |                                                                                                      | 0.000    |
| 6175 | zammad | localhost | zammad | Sleep   | 1     |              |                                                                                                      | 0.000    |
| 6176 | zammad | localhost | zammad | Sleep   | 52751 |              |                                                                                                      | 0.000    |
| 6177 | zammad | localhost | zammad | Sleep   | 12    |              |                                                                                                      | 0.000    |
| 6178 | zammad | localhost | zammad | Sleep   | 23440 |              |                                                                                                      | 0.000    |
| 6183 | zammad | localhost | zammad | Sleep   | 4627  |              |                                                                                                      | 0.000    |
| 6187 | zammad | localhost | zammad | Sleep   | 39    |              |                                                                                                      | 0.000    |
| 6188 | root   | localhost | zammad | Query   | 38    | Sending data | INSERT INTO authorizations (provider, uid, username, user_id, created_at, updated_at) select distinc | 0.000    |
| 6189 | zammad | localhost | zammad | Sleep   | 52523 |              |                                                                                                      | 0.000    |
| 6190 | zammad | localhost | zammad | Sleep   | 238   |              |                                                                                                      | 0.000    |
| 6192 | zammad | localhost | zammad | Sleep   | 34    |              |                                                                                                      | 0.000    |
| 6230 | zammad | localhost | zammad | Sleep   | 1     |              |                                                                                                      | 0.000    |
| 6245 | zammad | localhost | zammad | Sleep   | 27583 |              |                                                                                                      | 0.000    |
| 7006 | zammad | localhost |        | Sleep   | 287   |              |                                                                                                      | 0.000    |
| 7008 | zammad | localhost | zammad | Sleep   | 278   |              |                                                                                                      | 0.000    |
| 7013 | zammad | localhost | zammad | Sleep   | 44    |              |                                                                                                      | 0.000    |
| 7014 | root   | localhost |        | Query   | 0     | starting     | show processlist                                                                                     | 0.000    |
+------+--------+-----------+--------+---------+-------+--------------+------------------------------------------------------------------------------------------------------+----------+
Uptime: 150790  Threads: 19  Questions: 3435002  Slow queries: 796  Opens: 184  Open tables: 177  Queries per second avg: 22.780

“Queries per second avg” starts at around 500 and then gradually decreases.
“Slow queries” start to show up after the first ~30min of the initial LDAP sync.
The “INSERT INTO authorizations …” statement only takes <=2seconds in the beginning and gradually icreases (38 seconds in this excerpt).

#---/etc/mysql/conf.d/zammad.cnf---
[client]
default_character_set = utf8

[mysql]
default_character_set = utf8

[mysqld]
collation_server = utf8_bin
init_connect = 'SET NAMES utf8'
character_set_server = utf8
max_allowed_packet = 128M

innodb_buffer_pool_size = 11GiB                                 # i tried to give mariadb as much RAM as possible
innodb_flush_log_at_trx_commit = 2                              # this is supposed to speed up flushing to disk at the expense of possible dataloss when an outage occurs
innodb_flush_method = O_DIRECT

I also enabled the mariadb query log once to check wether mariadb is just waiting for input from ldap, but that was not the case.
There are plenty of queries being executed.


This is all in a sandboxed testenvironment btw.
It feels like the mariadb is the bottleneck but i’m running out of ideas.
Any help or suggestions are welcome =) Thanks!

My proposed Workaround:

To keep the downtime of our zammad instance at a minimum for the migration i am pursuing the following approach:

  • Performing migration & updates in a sandboxed environment while keeping the production zammad instance available to the public
  • Performing initial LDAP Sync also in the sandboxed environment
  • Extracting the zammad.users & zammad.authorizations tables from the MariaDB of the now up-to-date and synced zammad instance
  • Starting the actual downtime for our zammad instance
  • Performing migration & updates again on the actual target machine
  • Applying the previously extracted mysqldumps of zammad.users & zammad.authorizations tables on the target machine’s MariaDB
  • Performing a LDAP Sync (this time its rather fast, i tested that)
  • Ending the downtime

My question concerning this workaround is “What could possibly go wrong?” =)
E.g. does an LDAP Import Job write to any other of zammad’s MySQL tables which would now be missing important entries?

Kind regards,
Julian