[Date Prev][Date Next]
[Chronological]
[Thread]
[Top]
Performance issues lately.
- To: openldap-technical@openldap.org
- Subject: Performance issues lately.
- From: Jorgen Lundman <lundman@lundman.net>
- Date: Sun, 14 Nov 2010 19:13:35 +0900
- Dkim-signature: v=1; a=rsa-sha256; c=relaxed/relaxed; d=lundman.net; s=dkim; t=1289697230; bh=KRRBbApiphnCMMXi1pQNrkI2Nsy7T5RU4VMGCZht3A4=; h=Message-ID:Date:From:MIME-Version:To:Subject:Content-Type: Content-Transfer-Encoding; b=PTWYOz4KieiLow2IUih0AKop3K104ZD7Ue5AacHnbVFPrrOsITV87foZtsvvxVHFp /z9Oi2/pc9cu0HJbCeMRDVK+TJ/oTr+E07C5M2oYhITQv9feXH/xkWtsd2Hy6GMdIh PUTwzWtYJYUoeRPcSb7LlQgK1w83iXCTPB5xpxt4=
- User-agent: Mozilla/5.0 (Windows; U; Windows NT 6.1; en-US; rv:1.9.1.15) Gecko/20101027 SeaMonkey/2.0.10
Hello list,
Solaris 10u8
db-4.8.30.NC
openldap-2.4.23
So in the last week, simple queries have been really slow. For example:
# time /usr/local/bin/ldapsearch -h 0 -D cn=admin,dc=company,dc=com -x -w pass
-b ou=mail,dc=company,dc=com mail=testlookup@domain.com
1m21s
Of course "mail" in indexed. The server is dedicated to LDAP (test server) so
there are no other connections. Not even syncrepl connection.
I have checked the usual things, memory usage, BDB cache, and disk IO. All seem
to be within reasonable limits. Then I went deeper.
I started trussing it, and it seems to send the query reply nearly right away,
then sit around 200 seconds before we send a few more bytes and exit.
I tried out db_stat on various db, and found it is also really slow on stat on
"id2entry.bdb". For example:
# time /usr/local/BerkeleyDB.4.8/bin/db_stat -d id2entry.bdb
2m32s
So, trussing that call (including all calls in libdb-4.2):
19700/1@1: 0.0001 -> libdb-4.8:__db_stat_print_pp(0x419920, 0x0, 0x412c30,
0x4146a0, 0xfffffd7fffdff880, 0xfffffd7fffdff824)
19700/1: 0.0009 time() = 128972
5450
19700/1: 0.0001 brk(0x0041EC20) = 0
19700/1: 0.0001 brk(0x00422C20) = 0
19700/1: 0.0001 open("/usr/share/lib/zoneinfo/Japan", O_RDONLY) = 4
19700/1: 0.0000 fstat(4, 0xFFFFFD7FFFDFF880) = 0
19700/1: 0.0001 read(4, 0xFFFFFD7FFEEA0880, 125) = 125
19700/1: T Z i f\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\003\0\0\003\0\0\0
\0
19700/1: \0\0\0\t\0\0\003\0\0\0\fC3CE85 pD7 >1E90D7EC1680D8F91690D9CBF8
80
19700/1: DB071D10DBABDA80DCE6FF10DD8BBC80020102010201020102\0\0 ~90\0\0
\0
19700/1: \08CA00104\0\0 ~90\0\b C J T\0 J D T\0 J S T\0\0\0\0\0\0\0
19700/1: 0.0000 close(4) = 0
19700/1: 0.0002 ioctl(1, TCGETA, 0xFFFFFD7FFFDFE8B0) = 0
19700/1: 0.0000 fstat(1, 0xFFFFFD7FFFDFE840) = 0
19700/1: 0.0001 write(1, 0xFFFFFD7FFF006764, 36) = 36
19700/1: S u n N o v 1 4 1 8 : 0 4 : 1 0 2 0 1 0\t L o c a l
t
19700/1: i m e\n
19700/1: 589.8794 write(1, 0xFFFFFD7FFF006764, 25)
= 25
19700/1: 5 3 1 6 2\t B t r e e m a g i c n u m b e r\n
19700/1: 0.0046 write(1, 0xFFFFFD7FFF006764, 23) = 23
Not entirely sure why a write (everything leading up) to stdout takes 589 seconds.
I have tried rebuilding the whole database with slapadd but made no difference.
I put all DB files in /tmp on x4540 (has 32G RAM) and yet, still 2mins to do
db_stat.
General db_stat -m output:
4GB Total cache size
8 Number of caches
8 Maximum number of caches
512MB Pool individual cache size
0 Maximum memory-mapped file size
0 Maximum open file descriptors
0 Maximum sequential buffer writes
0 Sleep after writing maximum sequential buffers
0 Requested pages mapped into the process' address space
407M Requested pages found in the cache (99%)
38 Requested pages not found in the cache
425405 Pages created in the cache
38 Pages read into the cache
425427 Pages written from the cache to the backing file
0 Clean pages forced from the cache
0 Dirty pages forced from the cache
0 Dirty pages written by trickle-sync thread
425427 Current total page count
425427 Current clean page count
0 Current dirty page count
524296 Number of hash buckets used for page location
4096 Assumed page size used
407M Total number of times hash chains searched for a page (407904893)
32 The longest hash chain searched for a page
466M Total number of hash chain entries checked for page (466861223)
0 The number of hash bucket locks that required waiting (0%)
0 The maximum number of times any hash bucket lock was waited for (0%)
0 The number of region locks that required waiting (0%)
0 The number of buffers frozen
0 The number of buffers thawed
0 The number of frozen buffers freed
425538 The number of page allocations
0 The number of hash buckets examined during allocations
0 The maximum number of hash buckets examined for an allocation
0 The number of pages examined during allocations
0 The max number of pages examined for an allocation
0 Threads waited on page I/O
0 The number of times a sync is interrupted
Pool File: id2entry.bdb
16384 Page size
0 Requested pages mapped into the process' address space
13M Requested pages found in the cache (99%)
2 Requested pages not found in the cache
163449 Pages created in the cache
2 Pages read into the cache
163451 Pages written from the cache to the backing file
Pool File: mail.bdb
4096 Page size
0 Requested pages mapped into the process' address space
2797594 Requested pages found in the cache (99%)
2 Requested pages not found in the cache
3335 Pages created in the cache
2 Pages read into the cache
3337 Pages written from the cache to the backing file
-rw-r--r-- 1 root root 168 Nov 14 12:54 DB_CONFIG
-rw------- 1 root root 3.8M Nov 14 14:03 DNSData.bdb
-rw------- 1 root root 5.4M Nov 14 14:03 DNSHostName.bdb
-rw------- 1 root root 3.3M Nov 14 14:03 DNSIPAddr.bdb
-rw------- 1 root root 2.7M Nov 14 14:03 DNSType.bdb
-rw------- 1 root root 24K Nov 14 12:54 __db.001
-rw------- 1 root root 180M Nov 14 18:28 __db.002
-rw------- 1 root root 512M Nov 14 13:45 __db.003
-rw------- 1 root root 512M Nov 14 14:35 __db.004
-rw------- 1 root root 512M Nov 14 14:40 __db.005
-rw------- 1 root root 512M Nov 14 13:45 __db.006
-rw------- 1 root root 512M Nov 14 13:45 __db.007
-rw------- 1 root root 512M Nov 14 13:45 __db.008
-rw------- 1 root root 512M Nov 14 14:35 __db.009
-rw------- 1 root root 512M Nov 14 14:27 __db.010
-rw------- 1 root root 160K Nov 14 12:54 __db.011
-rw------- 1 root root 1.2M Nov 14 18:25 __db.012
-rw------- 1 root root 32K Nov 14 12:54 __db.013
-rw------- 1 root root 2.1M Nov 14 14:03 accountStatus.bdb
-rw-r--r-- 1 root root 2.0K Nov 14 16:12 alock
-rw------- 1 root root 536K Nov 14 14:03 deliveryMode.bdb
-rw------- 1 root root 621M Nov 14 14:07 dn2id.bdb
-rw------- 1 root root 172M Nov 14 14:03 entryCSN.bdb
-rw------- 1 root root 125M Nov 14 14:03 entryUUID.bdb
-rw------- 1 root root 17M Nov 14 14:03 gecos.bdb
-rw------- 1 root root 1.8M Nov 14 14:03 gidNumber.bdb
-rw------- 1 root root 2.5G Nov 14 14:40 id2entry.bdb
-rw------- 1 root root 50M Nov 14 16:12 log.0000000266
-rw------- 1 root root 13M Nov 14 14:03 mail.bdb
-rw------- 1 root root 3.2M Nov 14 14:03 mailAlternateAddress.bdb
-rw------- 1 root root 8.7M Nov 14 14:03 o.bdb
-rw------- 1 root root 4.9M Nov 14 14:03 objectClass.bdb
-rw------- 1 root root 1.3M Nov 14 14:03 radiusGroupName.bdb
-rw------- 1 root root 20M Nov 14 14:03 uid.bdb
-rw------- 1 root root 17M Nov 14 14:03 uidNumber.bdb
checkpoint 128 15
cachesize 5000
idlcachesize 15000
overlay syncprov
syncprov-checkpoint 100 10
syncprov-sessionlog 1000
# DB_CONFIG FILE. Warning, these entries are only written if the DB_CONFIG
# file DOES NOT EXIST. So if you change any of these values, you will need
# to remove the file, then restart slapd.
dbconfig set_lk_detect DB_LOCK_DEFAULT
dbconfig set_lg_max 52428800
dbconfig set_cachesize 4 0 8
dbconfig set_flags db_log_autoremove
dbconfig set_lk_max_objects 1500
dbconfig set_lk_max_locks 1500
dbconfig set_lk_max_lockers 1500
# DB_CONFIG FILE.
Any suggestions? Must have hit some limit somewhere I guess.
Lund