This bug is created as a clone of upstream ticket:
https://pagure.io/389-ds-base/issue/50674

#### Issue Description
Operation etime can be a mystery... why is it so long ?
We need to gather internal info but debug log are noisy and disturb the result itself.
This ticket is a proof of concept of kind of raw metrics logged on demand (with appropriate  access log level). Being buffered logging has no impact on the operation itself.



#### Package Version and Platform
all version


#### Steps to reproduce
The problem raise with substring search with very long initial assertion that is common to a large number of entries. Parallel requests create a bottleneck on dbc_get and etime appears as a mystery.

#### Actual results
No stat related to an operation


#### Expected results
    [25/Oct/2019:16:23:28.620364576 +0200] conn=1 op=1 SRCH base="dc=example,dc=com" scope=2 filter="(sn=user*)" attrs=ALL
    [25/Oct/2019:16:23:28.623678548 +0200] conn=1 op=1 STAT attribute=objectclass key(eq)=referral --> count 0
    [25/Oct/2019:16:23:28.623697194 +0200] conn=1 op=1 STAT attribute=sn key(sub)=ser --> count 21
    [25/Oct/2019:16:23:28.623698763 +0200] conn=1 op=1 STAT attribute=sn key(sub)=use --> count 24
    [25/Oct/2019:16:23:28.623700176 +0200] conn=1 op=1 STAT attribute=sn key(sub)=^us --> count 20
    [25/Oct/2019:16:23:28.623701596 +0200] conn=1 op=1 RESULT err=0 tag=101 nentries=20 etime=0.003488420