Large delay before transmitting search result

["Rene B. Elgaard" <rene.bach.elgaard@gmail.com>]

Hello,

OpenLDAP 2.4.26 + BerkeleyDB 5.2.28, also seen on OpenLDAP 2.4.22 + BerkeleyDB 4.6.21

I am trying to investigate a response time issue.
Basically I am doing a search with ldapsearch that results in the transfer of an 8.5 Mb binary entry. This takes around 800 ms measured on the server itself from the request has been received until the response has been delivered..
Looking at what is going on on the network I see a large delay between slapd receiving the search request and the actual start of the transfer. This delay accounts for around 600ms.

So what is going on during this time ?

I am on Solaris 10, so I use dtrace to look at slapd, and it turns out that it calls memmove(<ADDR>,<ADDR>  + 1, ~8.5 Mb).
That is it shifts the result 1 byte, and it does this 4 times. Each memmove takes around 150 ms, which accounts almost completely for the delay before doing the transfer over network.
I have written a small C program which does the same memmove and verified that on my setup, it does indeed take 150ms to shift 8.5 Mb 1 byte.

The stacktrace up until each memmove is

  0  42451                    memmove:entry *** Moving from 213650401 to 213650402 ***
              libc.so.1`memmove
              slapd`0x82461c9
              slapd`ber_printf+0x4ff
              slapd`slap_send_search_entry+0x1a94
              slapd`bdb_search+0x1ce0
              slapd`fe_op_search+0x574
              slapd`do_search+0xc82
              slapd`0x80927a9
              slapd`0x8092d21
              slapd`0x8210034

The first line shows the source and destination address for memmove. The numbers themselves are not interesting, but the difference (1) is.

Why is it shifting the buffer 1 byte ?
If this could be optimized somehow, it could lead to a huge improvement in response time.

Thanks,
Rene