389-ds-base

#49942 Ticket 49887: Clean thread local usage
Closed by spichugi. Opened by firstyear.
firstyear/389-ds-base 49941-clean-thread-local  into  master

Download 49942.patch

Clean the thread local usage of the logging system to be more inline with
pthread's intent, remove bad practices of case/switch get setters, and change
the types to be more effecient struct types. Generally make it better

https://pagure.io/389-ds-base/issue/49941

Author: William Brown william@blackhats.net.au

rebased onto db4c991229ac587d776908fbf2697235d2ea4317

rebased onto db4c991229ac587d776908fbf2697235d2ea4317

This patch breaks the internal operation logging. Its not incrementing the op count for internal operations that are done outside of worker threads. That's why in main.c I had an explicit initialization for the main thread.

[07/Sep/2018:11:19:23.448696877 -0400] conn=Internal(0) op=0(0) RESULT err=0 tag=48 nentries=1 etime=0.0000101904
[07/Sep/2018:11:19:23.452060677 -0400] conn=Internal(0) op=0(0) RESULT err=0 tag=48 nentries=0 etime=0.0003609864
[07/Sep/2018:11:19:23.456748531 -0400] conn=Internal(0) op=0(0) MOD dn="dc=example,dc=com"
[07/Sep/2018:11:19:23.457938971 -0400] conn=Internal(0) op=0(0) RESULT err=0 tag=48 nentries=0 etime=0.0001214719
[07/Sep/2018:11:19:53.461206310 -0400] conn=Internal(0) op=0(0) MOD dn="dc=example,dc=com"
[07/Sep/2018:11:19:53.468369376 -0400] conn=Internal(0) op=0(0) RESULT err=0 tag=48 nentries=0 etime=0.0007184712
[07/Sep/2018:11:20:23.472024900 -0400] conn=Internal(0) op=0(0) MOD dn="dc=example,dc=com"
[07/Sep/2018:11:20:23.475223861 -0400] conn=Internal(0) op=0(0) RESULT err=0 tag=48 nentries=0 etime=0.0003228102

This should look like:

[07/Sep/2018:11:39:43.687726972 -0400] conn=Internal(0) op=0(102) RESULT err=0 tag=48 nentries=0 etime=0.0000024356
[07/Sep/2018:11:39:43.687750902 -0400] conn=Internal(0) op=0(103) ADD dn="cn=monitor,cn=NetscapeRoot,cn=ldbm database,cn=plugins,cn=config"
[07/Sep/2018:11:39:43.687790827 -0400] conn=Internal(0) op=0(103) RESULT err=68 tag=48 nentries=0 etime=0.0000045336
[07/Sep/2018:11:39:43.687804508 -0400] conn=Internal(0) op=0(104) ADD dn="cn=index,cn=NetscapeRoot,cn=ldbm database,cn=plugins,cn=config"
[07/Sep/2018:11:39:43.687833521 -0400] conn=Internal(0) op=0(104) RESULT err=68 tag=48 nentries=0 etime=0.0000032260
[07/Sep/2018:11:39:43.687846597 -0400] conn=Internal(0) op=0(105) ADD dn="cn=encrypted attributes,cn=NetscapeRoot,cn=ldbm database,cn=plugins,cn=config"
[07/Sep/2018:11:39:43.687873425 -0400] conn=Internal(0) op=0(105) RESULT err=68 tag=48 nentries=0 etime=0.0000030488

Simply restarting the server will show the difference in behavior with and without your patch.

@mreynolds Thanks for checking - I'll look into why this is.

Okay, when you say "outside of worker threads" what do you mean? all threads in this new setup are "workers" now - they initialise on first use rather that explicit init. So long as the _start() function is called, they get a valid structure. I would suspect that it's something else going on that I need to check into. How did you create the conditions here to highlight this issue? 

[08/Sep/2018:16:50:55.903789304 +1000] conn=Internal(0) op=0(80) SRCH base="cn=userRoot,cn=ldbm database,cn=plugins,cn=config" scope=0 filter="objectclass=*" attrs=ALL
[08/Sep/2018:16:50:55.904022552 +1000] conn=Internal(0) op=0(80) RESULT err=0 tag=48 nentries=1 etime=0.0000258169
[08/Sep/2018:16:50:55.906507206 +1000] conn=Internal(0) op=0(81) SRCH base="cn=index,cn=userRoot,cn=ldbm database,cn=plugins,cn=config" scope=2 filter="(objectclass=nsIndex)" attrs=ALL
[08/Sep/2018:16:50:55.909551731 +1000] conn=Internal(0) op=0(81) RESULT err=0 tag=48 nentries=27 etime=0.0003070941
[08/Sep/2018:16:50:55.910020883 +1000] conn=Internal(0) op=0(82) SRCH base="cn=encrypted attributes,cn=userRoot,cn=ldbm database,cn=plugins,cn=config" scope=2 filter="(objectclass=nsAttributeEncryption)" attrs=ALL

Fixed, code incoming,

rebased onto dc9e2c4371329d69a77b6fc25091e628014b827a

In the original version of util.c due to the nature of the pointers this check (confusingly) was checking td_conn - I read it as "is td_conn > 0" rather than "is td_conn a valid pointer". So my check would check connid > 0 and op_state != null. THis caused all op_id's to follow the second branch,

This now checks only the struct pointer instead, and it cleans the issues up

In general I think this could be redesigned to use Op struct pointer checks rather than thread local, but I only have so much time in a day.

Thanks - LGTM!! Ack!

Thank you! I'll rebase and merge :)

rebased onto e59b309c54adcb3d992d568936e1983fba00b501

Pull-Request has been merged by firstyear

Turns out internal operation logging is still completely broken. The op numbers and counts are wrong and not reliable :-( Investigating this in https://pagure.io/389-ds-base/issue/49995

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 pull request has been cloned to Github as issue and is available here:
- https://github.com/389ds/389-ds-base/issues/3001

If you want to continue to work on the PR, please navigate to the github issue,
download the patch from the attachments and file a new pull request.

Thank you for understanding. We apologize for all inconvenience.

Pull-Request has been closed by spichugi
Metadata
None
No Tags
Static archive. pagure.io was sunset in 2026; this is a read-only snapshot.
Red Hat Logo

Fedora is sponsored by Red Hat. Learn more about the relationship between Red Hat and Fedora »

© Red Hat, Inc. and others.