>>> Christopher Paul <[email protected]> schrieb am 31.12.2022 um >>> 00:35 in Nachricht <ph7pr12mb571022a0a3ea320f926ea69c9d...@ph7pr12mb5710.namprd12.prod.outlook.com>
> Hello OpenLDAP-Technical, > > > > Using the oldie but goodie LDAP performance testing tool, SLAMD, I've been > doing performance tests. What I found was that stats logging (olcLogLevel: > 256) degrades performance significantly. A pity, because it is recommended in > the manual. Also, it considered very useful by those of us who've been > running OpenLDAP for a while. > > > > The test was performed on Dell Workstation Intel Xeon E-2630 v3 @ 2.40Ghz > Xen 4.6.5 hypervisor running Linux 4.4.0 Ubuntu 16.04, 4 vcpus pinned to the > hypervisor and the other 12 pinned to the OpenLDAP VM. The OpenLDAP VM was > allocated 8GB RAM and runs OpenLDAP 2.5.13 (Symas RPM build) on RedHat 8.7. > Ten thousand fake users were created in an OU=FakePeople for testing. > > > > I am aware that contention with disk I/O can cause problems, so I tried > eliminating systemd-journald and rsyslogd in order to test "pure OpenLDAP" > response times but was not perfectly successful. I ran slapd in the > foreground using "slapd -d 256 ... 2>/dev/null". But then I noticed that > systemd-journald still was logging to "session-4.scope". I tried "systemctl > stop systemd-journald" and "systemctl stop systemd-journald.socket" and > "systemctl stop systemd-journald-dev-log.socket" but was not able to stop > systemd-journald from showing up using CPU in "htop". I tried limiting it > also by setting RateLimitIntervalSec=1s and RateLimitBurst=1 in > /etc/system/journald.conf. This reduced the logging but I still saw > "/usr/lib/system/systemd-journald" taking 100% of one vcpu during the > performance tests whenever olcLogLevel was set to 256. Did you try to revert systemd logging to ramdisk only (/run/log/journal/ (or so)) instead of /var/log/journal/? > > > > The test results I will include with this post are from the Asynchronous > Search Rate SLAMD job class using LDAPSearch filters of valid random values > for indexed attributeTypes "uid" and "mail" matching exact filters (equality > match). > > > > Using LogLevel 256, the Asynchronous Search Rate test with 3 clients, 2 > connection threads each (from laptop i7-1280P vPro Processor), OpenLDAP > returned an average 10,932 results completed per second with err=0 and > average 21ms response time. > > > > Then I ran ldapmodify to changetype: replace olcLogLevel to 0, reran the > same test, and saw OpenLDAP perform much better. The same test with > olcLogLevel=0 returned 84,286 results per second with err=0 (671% increase) > and average response time of 2.6 ms (88% decrease). Watching "htop" during > this test showed all vcpus firing a lot more evenly and hotter than the test > with olcLogLevel=256; it was very clear how efficient slapd can be without > having to do any logging. Maybe try each single bit of olcLogLevel to make a histogram which logging bit consumes most time. That would be 8 tests (for 8 bits). > > > > I ran several samples of each test and picked the best for each of > olcLogLevels I tested. I ran other tests like 3 and 4 clients times 50 > connections each, also ran Basic Bind Rate and saw similar patterns there. I > don't mind sharing my configs or the test data if anyone is interested. > > > > And so naturally, I am wondering if this is a known limitation and also > whether it is something that can be addressed or is a hard constraint. I > guess I had expected some impact as a result of logging (nothing comes for > free...) but not this much. Well, in general extra logging does not only mean some extra log output, but also formatting (like using printf()) or other conversions that may cost extra time. There are also profiling tools (like gprof) that might allow you some deeper insights, but that would require a rebuild of the software. Regards, Ulrich
