eDirectory performace, ZCM
Server specs:
Netware 6.5 SP8
eDirectory 8.8 SP5
Holds master replica
Memory: 3 GB
CPU: Intel Xeon Quadcore 1.87 GHz
We have a performance issue with eDirectory searches (via LDAP interface) when the searchrequest contains server-side sorting (controlType: 1.2.840.113556.1.4.473 (sortKeyList))
This control type (serverside LDAP sorting) is commonly used by Zenworks 10, when the tree is being browsed via administration webintrerface.
The Zenworks 10 ldap searches are issued with a LDAP_SCOPE_ONELEVEL [or scope: singleLevel (1) ] request, and is analogue with the PHP LDAP funcion ldap_list().
ldap_search() searches a scope of LDAP_SCOPE_SUBTREE [or scope:wholeSubtree (2) ]
ldap_read() searches a scope of LDAP_SCOPE_BASE [or scope: baseObject (0) ]
When the ldap_search() and ldap_read() are issued, the search - and the objects returned - are very fast! Meaning: a fraction of a second.
But, when a ldap_read() is issued with a serverside sort request - with index "cn" - , then the search is taking very (relativily) long time.
For example: a simple search in ROOT_DSE with no objects to return, is taking up to 3.5 seconds, and the CPU ulitization is getting very high (100%) under this operation.
The "slowness" is occuring on a Netware server (se specs. in the top of the document); the OES2 Linux server is a lot faster in this operation.
So: it seemes to be some kind of a bug in the eDirectory modules. I made this PHP script to emulate Zenworks 10 requests:
<?php
function utime () // Take time
{
$time = explode( " ", microtime());
$usec = (double)$time[0];
$sec = (double)$time[1];
return $sec + $usec;
}
$start = utime(); // Start time measurment
$ldap = ldap_connect("10.100.0.13"); // Make connection to the server
ldap_bind($ldap,"<adminusername>","<adminpassword> "); // Make a simple bind with administrator
$control_bytes = array("oid" =>"1.2.840.113556.1.4.473","value" =>"\x30\x84\x00\x00\x00\x0a\x30\x84\x00\x00\x00\x0 4\x04\x02cn"); // Define a controlType and sort request on "cn"
ldap_set_option($ldap,LDAP_OPT_SERVER_CONTROLS,arr ay($control_bytes)); // Enter controlbytes to $ldap handle
$sr2 = ldap_list($ldap, "", "(|(objectclass=iPrintPrinter)(objectclass=NDPSPri nter))",array("cn","objectclass","guid")); // Make a simple LDAP list in ROOT_DSE (no base defined)
$data2 = ldap_get_entries($ldap, $sr2); // Read entries
ldap_unbind($ldap); // When entries are returnes, terminate connection
$end = utime(); // Stop time measurment
$run = $end - $start; // Calculate time
echo "<br>Objects: ".$data2["count"]."<br>Time: " .$run; // Print number of objects returned and the searchtime!
?>
At the same time i was dstracing with +LDAP and +RECM on eDirectory server, the dstrace log looks as following:
[SNIP]
16:11:57 9C761400 LDAP: (148.160.250.50:15470)(0x0002:0x63) Search request:
base: ""
scope:1 dereference:0 sizelimit:0 timelimit:0 attrsonly:0
filter: "(|(objectclass=iPrintPrinter)(objectclass=NDPSPri nter))"
attribute: "cn"
attribute: "objectclass"
attribute: "guid"
16:11:57 9C761400 LDAP: (148.160.250.50:15470)(0x0002:0x63) Sort setup with index "cn"
16:11:57 9C761400 StrMan: Iter #968ac444 query ((Flags&1)==1) && (ParentID==32816) && (((Object_Class$262A$.Flags&8==1558) || ( <++
16:11:57 9C761400 StrMan: Iter #968ac444 setOrderIndex() for attr # 218
16:11:57 9C761400 StrMan: Iter #968ac444 query ++> Object_Class$262A$.Flags&8==1522)))
16:11:58 9C761400 StrMan: Iter #968ac444 index = CN$IX$220
16:11:58 9C761400 StrMan: Iter #968ac444 first( ID_INVALID)
16:12:00 9C761400 LDAP: (148.160.250.50:15470)(0x0002:0x63) Sending operation result 0:"":"" to connection 0x967552c0
16:12:00 9C761400 LDAP: (148.160.250.50:15470)(0x0003:0x42) DoUnbind on connection 0x967552c0
16:12:00 9C761400 LDAP: Connection 0x967552c0 closed
[SNIP]
Explanation of ID:s
ParentID==32816 is translated to "T=BS-TREE" (the root of tree)
Flags&8==1522 is translated to "NDPS Printer"
Flags&8==1558 is translated to "iPrint Printer"
.
Observe! When i issue the same search - WITHOUT the serverside sort request - the search is processed very fast: 0.04 seconds instead of 3.5!
Se DSTRACE log for this search request:
[SNIP]
16:14:40 9C761400 LDAP: (148.160.250.50:15568)(0x0002:0x63) DoSearch on connection 0x967552c0
16:14:40 9C761400 LDAP: (148.160.250.50:15568)(0x0002:0x63) Search request:
base: ""
scope:1 dereference:0 sizelimit:0 timelimit:0 attrsonly:0
filter: "(|(objectclass=iPrintPrinter)(objectclass=NDPSPri nter))"
attribute: "cn"
attribute: "objectclass"
attribute: "guid"
16:14:40 9C761400 StrMan: Iter #968ac244 query ((Flags&1)==1) && (ParentID==32816) && (((Object_Class$262A$.Flags&8==1558) || ( <++
16:14:40 9C761400 StrMan: Iter #968ac244 query ++> Object_Class$262A$.Flags&8==1522)))
16:14:40 9C761400 StrMan: Iter #968ac244 index = ParentID+CTS_IX
16:14:40 9C761400 StrMan: Iter #968ac244 first( ID_INVALID)
16:14:40 9C761400 LDAP: (148.160.250.50:15568)(0x0002:0x63) Sending operation result 0:"":"" to connection 0x967552c0
16:14:40 9C761400 LDAP: (148.160.250.50:15568)(0x0003:0x42) DoUnbind on connection 0x967552c0
16:14:40 9C761400 LDAP: Connection 0x967552c0 closed
[SNIP]
Best regards,
Heiti Ernits
Borås, Sweden
|
Threaded Mode
