While working on virtual attribute lock contention (ticket 512). I setup a stap script to monitor that contention. The script also reported a high contention on cos cache lock This is an unexpected side effect of the script that was suppose to only report virtual attribute lock contention.
How to reproduce
- Identify the cos cache lock address echo "print cache_lock" | gdb /usr/bin/ns-slapd `ps -ef |grep ns-slapd | grep -v grep | awk '{print $2}'` | grep gdb - use the attached stap script. Use the test case described in ticket512.
The script will report (/tmp/stap_output) a set of high contention lock. One of them is the cos cache_lock (look for its address for example 0x1423ad0) The data showing the contention (into /tmp/stap_output)
lock 0x1423ad0 contended 37435 times, 16800 avg us ... Histogram 0x1423ad0 value |-------------------------------------------------- count 0 |@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@ 7524 1000 |@@@@@ 757 2000 |@@@@@ 822 3000 |@@@@@@ 909 4000 |@@@@@ 830 5000 |@@@@ 754 6000 |@@@@@@ 1003 7000 |@@@@@ 836 8000 |@@@@@ 802 9000 |@@@@@@ 1014 10000 |@@@@@@ 958 11000 |@@@@@ 838 12000 |@@@@ 752 13000 |@@@@@@ 946 14000 |@@@@@ 856 15000 |@@@@@ 819 16000 |@@@@@@ 982 17000 |@@@@ 714 18000 |@@@@@ 788 19000 |@@@@@@ 960 20000 |@@@@@ 850 21000 |@@@@ 672 22000 |@@@@ 713 23000 |@@@@@ 800 24000 |@@@@ 657 25000 |@@@@ 615 26000 |@@@@@ 763 27000 |@@@ 558 28000 |@@@ 488 29000 |@@@ 585 30000 |@@@ 520
30000 |@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@ 6350
attachment vattr_contention.stp
attachment vattr_contention.sh
'''Here is the current status'''
{{{ testcase: rseach filter: (&(|(uid=tcos1)(uid=tcos2)(uid=tcos3)(uid=tcos4)(uid=tcos5)(uid=tcos6)(uid=tcos7)(uid=tcos8)(uid=tcos9)(uid=tcos10))(postalcode=value1) (employeeNumber=value1) (carLicense=value1) (departmentNumber=value1) (employeeType=value1)) attrs: postalcode employeeNumber givenname carLicense departmentNumber employeeType #entry returned: 10
master cache_lock (% contention ~ 0.2%) #trie: ~700,000 #contended: 1389 times, 12804 avg us Histogram 0x1ad9080 value |-------------------------------------------------- count 0 |@@@@@@@@@@@@@@@@@@@@@@@@@ 50 1000 |@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@ 71 2000 |@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@ 88 3000 |@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@ 77 4000 |@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@ 97 5000 |@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@ 72 6000 |@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@ 60 7000 |@@@@@@@@@@@@@@@@@@@@@@@@@@@ 55 8000 |@@@@@@@@@@@@@@@@@@@@@@ 44 9000 |@@@@@@@@@@@@@@@@@@@@ 41 10000 |@@@@@@@@@@@@@@@@@@@@@@@ 46 11000 |@@@@@@@@@@@@@@@@@@@@@@@@@ 51 12000 |@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@ 61 13000 |@@@@@@@@@@@@@@@@ 33 14000 |@@@@@@@@@@@@@@@ 30 15000 |@@@@@@@@@@@@@@@@@@@@@@@@@ 51 16000 |@@@@@@@@@@@@@@@@@@@ 38 17000 |@@@@@@@@@@@@@@@@@@ 37 18000 |@@@@@@@@@@@@@@@@@@ 36 19000 |@@@@@@@@@@@@@@@@@@@@@@@@@@ 53 20000 |@@@@@@@@@@@@@@@@ 32 21000 |@@@@@@@@@@@@@@@@@ 34 22000 |@@@@@@@@@@@@@@@@@@ 36 23000 |@@@@@@@@@@@ 22 24000 |@@@@@@@@ 16 25000 |@@@@@@@@@@ 21 26000 |@@@@@@@@@@@ 23 27000 |@@@@@@ 12 28000 |@@@@@ 11 29000 |@@@@@@ 12 30000 |@ 3
30000 |@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@ 76
1.3.1 cache_lock (% contention ~ 1.1%) #tries: ~500,000 #contended 5546 times, 12963 avg us Histogram 0x120bcc0 value |-------------------------------------------------- count 0 |@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@ 501 1000 |@@@@@@@@@@@@@@@@@@@@ 224 2000 |@@@@@@@@@@@@@@@@@@@@@@@@ 271 3000 |@@@@@@@@@@@@@@@@@@@ 215 4000 |@@@@@@@@@@@@@@@@@@@@@@@ 259 5000 |@@@@@@@@@@@@@@@@@@@@@@@@ 266 6000 |@@@@@@@@@@@@@@@@@@@@@ 231 7000 |@@@@@@@@@@@@@@@@ 177 8000 |@@@@@@@@@@@@@@@@@@@ 215 9000 |@@@@@@@@@@@@@@@@@@@@@ 239 10000 |@@@@@@@@@@@@@@@@@@@ 209 11000 |@@@@@@@@@@@@@@@@@ 196 12000 |@@@@@@@@@@@@@@@@@@ 204 13000 |@@@@@@@@@@@@@@@ 165 14000 |@@@@@@@@@@@@@@@ 165 15000 |@@@@@@@@@@@@@@@ 171 16000 |@@@@@@@@@@@@@@ 154 17000 |@@@@@@@@@@@ 128 18000 |@@@@@@@@@@@@ 135 19000 |@@@@@@@@@@@@@@ 154 20000 |@@@@@@@@@@@@ 134 21000 |@@@@@@@@@@@ 123 22000 |@@@@@@@@@@ 110 23000 |@@@@@@@ 78 24000 |@@@@@@@@@ 103 25000 |@@@@@@@@ 94 26000 |@@@@@ 61 27000 |@@@@@@@ 77 28000 |@@@@ 48 29000 |@@@@ 50 30000 |@@@ 33
30000 |@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@ 356
}}}
- The cos cache is caching cos definitions. When cos definition changes (add/del/mod of a cos definition) the cos cache is rebuilt. So for standard lookup operation, the cos cache is just protected by a refcnt. Change of cos definition is only allowed when refcnt=0. The cos cache lock protects a very short critical section: increase/decrease a refcnt. The only modification I can think of is to change the refcnt into a RWlock but the benefits would be mimimum compare to what was obtained with ticket 512.
'''Here are the next steps'''
- ticket 512 provides a large improvement for the cos caching and contention, I propose to close this ticket as duplicate of 512 and to reopen it if a customer is complaining about cos contention.
Metadata Update from @tbordaz: - Issue assigned to tbordaz - Issue set to the milestone: 1.3.2 - 06/13 (June)
389-ds-base is moving from Pagure to Github. This means that new issues and pull requests will be accepted only in 389-ds-base's github repository.
This issue has been cloned to Github and is available here: - https://github.com/389ds/389-ds-base/issues/615
If you want to receive further updates on the issue, please navigate to the github issue and click on subscribe button.
subscribe
Thank you for understanding. We apologize for all inconvenience.
Metadata Update from @spichugi: - Issue close_status updated to: wontfix (was: Duplicate)
Login to comment on this ticket.