openldap-software October 2009

openldap-software@openldap.org

44 participants
45 discussions

syncrepl problem with 2.4.19
by Christoph Herrmann 21 Oct '09

21 Oct '09

Dear all, we want to update our openldap-2.3.39 infrastructure to openldap 2.4.19. For that we did some stress tests to an openldap-2.4.19 test infrastructure. we are running the tests in a single master environment with 5 slave servers, all with openldap-2.4.19. All machines are running ntpd and are in sync: ntpq -p: server remote refid st t when poll reach delay offset jitter =========================================================================================================== ldapma01 *172.26.248.222 172.26.228.131 6 u 2 16 377 0.291 -0.812 0.027 ldapsl01 *172.26.248.222 172.26.228.131 6 u 10 64 377 0.272 -4.486 0.024 ldapsl02 *172.26.248.222 172.26.228.131 6 u 2 32 377 0.244 -1.424 0.006 ldapsl03 *172.26.248.222 172.26.228.131 6 u 15 32 377 0.195 -3.411 0.056 ldapsl04 *172.26.248.222 172.26.228.131 6 u 2 16 377 0.258 -0.039 0.017 ldapsl05 *172.26.248.222 172.26.228.131 6 u 4 32 377 0.260 -0.040 0.027 this is our syncrepl config: master/provider: overlay syncprov syncprov-checkpoint 100 10 syncprov-sessionlog 100 slave/consumer: syncrepl rid=467 provider=ldap://ldapma01:389 type=refreshAndPersist retry=2,30,15,40,60,+ searchbase="o=example,c=de" filter="(objectClass=*)" scope=sub schemachecking=on bindmethod=simple binddn="cn=replica,ou=replica,o=example,c=de" credentials="replica" updateref ldap://ldapma01:389 During the tests we always run in to problems with syncrepl. We are doing tests in the way: bind; add|modify|delete; unbind; wait for n ms; bind .... (10 =< n =< 100) depending on the time between the requests, about 1% of our write requests will not be synchronized to any off the slaves. It seems, the the master send the syncreplrequests out of sync, and all slaves reject syncing with the message: CSN too old, ignoring ... What can we do, to solve that problem? attached you will find one add example and one delete example. (the logs on all slaves are identical) ADD: master.log: Oct 20 09:47:18 ldapma01 slapd[8354]: conn=2121 fd=15 ACCEPT from IP=172.26.248.57:50294 (IP=0.0.0.0:389) Oct 20 09:47:18 ldapma01 slapd[8354]: conn=2121 op=0 BIND dn="uid=ladmin,ou=verwaltung,o=example,c=de" method=128 Oct 20 09:47:18 ldapma01 slapd[8354]: conn=2121 op=0 BIND dn="uid=ladmin,ou=Verwaltung,o=example,c=de" mech=SIMPLE ssf=0 Oct 20 09:47:18 ldapma01 slapd[8354]: conn=2121 op=0 RESULT tag=97 err=0 text= Oct 20 09:47:18 ldapma01 slapd[8354]: conn=2121 op=1 ADD dn="cn=15,ou=slamdtest,o=example,c=de" Oct 20 09:47:18 ldapma01 slapd[8354]: slap_queue_csn: queing 0x9fdf298a 20091020074718.210361Z#000000#000#000000 Oct 20 09:47:18 ldapma01 slapd[8354]: syncprov_sendresp: cookie=rid=332,csn=20091020074718.210361Z#000000#000#000000 Oct 20 09:47:18 ldapma01 slapd[8354]: syncprov_sendresp: cookie=rid=330,csn=20091020074718.210361Z#000000#000#000000 Oct 20 09:47:18 ldapma01 slapd[8354]: syncprov_sendresp: cookie=rid=467,csn=20091020074718.210361Z#000000#000#000000 Oct 20 09:47:18 ldapma01 slapd[8354]: syncprov_sendresp: cookie=rid=442,csn=20091020074718.210361Z#000000#000#000000 Oct 20 09:47:18 ldapma01 slapd[8354]: syncprov_sendresp: cookie=rid=466,csn=20091020074718.210361Z#000000#000#000000 Oct 20 09:47:18 ldapma01 slapd[8354]: conn=2121 op=1 RESULT tag=105 err=0 text= Oct 20 09:47:18 ldapma01 slapd[8354]: slap_graduate_commit_csn: removing 0x1218ee70 20091020074718.210361Z#000000#000#000000 Oct 20 09:47:18 ldapma01 slapd[8354]: conn=2121 op=2 UNBIND Oct 20 09:47:18 ldapma01 slapd[8354]: conn=2121 fd=15 closed Oct 20 09:47:18 ldapma01 slapd[8354]: conn=2122 fd=15 ACCEPT from IP=172.26.248.57:50295 (IP=0.0.0.0:389) Oct 20 09:47:18 ldapma01 slapd[8354]: conn=2122 op=0 BIND dn="uid=ladmin,ou=verwaltung,o=example,c=de" method=128 Oct 20 09:47:18 ldapma01 slapd[8354]: conn=2122 op=0 BIND dn="uid=ladmin,ou=Verwaltung,o=example,c=de" mech=SIMPLE ssf=0 Oct 20 09:47:18 ldapma01 slapd[8354]: conn=2122 op=0 RESULT tag=97 err=0 text= Oct 20 09:47:18 ldapma01 slapd[8354]: conn=2123 fd=19 ACCEPT from IP=172.26.248.57:50296 (IP=0.0.0.0:389) Oct 20 09:47:18 ldapma01 slapd[8354]: conn=2122 op=1 ADD dn="cn=16,ou=slamdtest,o=example,c=de" Oct 20 09:47:18 ldapma01 slapd[8354]: slap_queue_csn: queing 0xa450b98a 20091020074718.707969Z#000000#000#000000 Oct 20 09:47:18 ldapma01 slapd[8354]: conn=2123 op=0 BIND dn="uid=ladmin,ou=verwaltung,o=example,c=de" method=128 Oct 20 09:47:18 ldapma01 slapd[8354]: conn=2123 op=0 BIND dn="uid=ladmin,ou=Verwaltung,o=example,c=de" mech=SIMPLE ssf=0 Oct 20 09:47:18 ldapma01 slapd[8354]: conn=2123 op=0 RESULT tag=97 err=0 text= Oct 20 09:47:18 ldapma01 slapd[8354]: conn=2123 op=1 ADD dn="cn=17,ou=slamdtest,o=example,c=de" Oct 20 09:47:18 ldapma01 slapd[8354]: slap_queue_csn: queing 0x983f698a 20091020074718.719682Z#000000#000#000000 Oct 20 09:47:18 ldapma01 slapd[8354]: conn=2124 fd=20 ACCEPT from IP=172.26.248.57:50297 (IP=0.0.0.0:389) Oct 20 09:47:18 ldapma01 slapd[8354]: conn=2124 op=0 BIND dn="uid=ladmin,ou=verwaltung,o=example,c=de" method=128 Oct 20 09:47:18 ldapma01 slapd[8354]: conn=2124 op=0 BIND dn="uid=ladmin,ou=Verwaltung,o=example,c=de" mech=SIMPLE ssf=0 Oct 20 09:47:18 ldapma01 slapd[8354]: conn=2124 op=0 RESULT tag=97 err=0 text= Oct 20 09:47:18 ldapma01 slapd[8354]: conn=2124 op=1 ADD dn="cn=18,ou=slamdtest,o=example,c=de" Oct 20 09:47:18 ldapma01 slapd[8354]: slap_queue_csn: queing 0x9c6e798a 20091020074718.732501Z#000000#000#000000 Oct 20 09:47:18 ldapma01 slapd[8354]: conn=2123 op=1 RESULT tag=105 err=0 text= Oct 20 09:47:18 ldapma01 slapd[8354]: slap_graduate_commit_csn: removing 0x120f5400 20091020074718.719682Z#000000#000#000000 Oct 20 09:47:18 ldapma01 slapd[8354]: syncprov_sendresp: cookie=rid=332,csn=20091020074718.732501Z#000000#000#000000 Oct 20 09:47:18 ldapma01 slapd[8354]: syncprov_sendresp: cookie=rid=330,csn=20091020074718.732501Z#000000#000#000000 Oct 20 09:47:18 ldapma01 slapd[8354]: syncprov_sendresp: cookie=rid=467,csn=20091020074718.732501Z#000000#000#000000 Oct 20 09:47:18 ldapma01 slapd[8354]: syncprov_sendresp: cookie=rid=467,csn=20091020074718.719682Z#000000#000#000000 Oct 20 09:47:18 ldapma01 slapd[8354]: conn=2124 op=1 RESULT tag=105 err=0 text= Oct 20 09:47:18 ldapma01 slapd[8354]: slap_graduate_commit_csn: removing 0xa32039b8 20091020074718.732501Z#000000#000#000000 Oct 20 09:47:18 ldapma01 slapd[8354]: conn=2123 op=2 UNBIND Oct 20 09:47:18 ldapma01 slapd[8354]: syncprov_sendresp: cookie=rid=332,csn=20091020074718.719682Z#000000#000#000000 Oct 20 09:47:18 ldapma01 slapd[8354]: syncprov_sendresp: cookie=rid=330,csn=20091020074718.719682Z#000000#000#000000 Oct 20 09:47:18 ldapma01 slapd[8354]: conn=2124 op=2 UNBIND Oct 20 09:47:18 ldapma01 slapd[8354]: conn=2124 fd=20 closed Oct 20 09:47:18 ldapma01 slapd[8354]: syncprov_sendresp: cookie=rid=442,csn=20091020074718.732501Z#000000#000#000000 Oct 20 09:47:18 ldapma01 slapd[8354]: syncprov_sendresp: cookie=rid=442,csn=20091020074718.719682Z#000000#000#000000 Oct 20 09:47:18 ldapma01 slapd[8354]: syncprov_sendresp: cookie=rid=466,csn=20091020074718.732501Z#000000#000#000000 Oct 20 09:47:18 ldapma01 slapd[8354]: syncprov_sendresp: cookie=rid=466,csn=20091020074718.719682Z#000000#000#000000 Oct 20 09:47:18 ldapma01 slapd[8354]: conn=2122 op=1 RESULT tag=105 err=0 text= Oct 20 09:47:18 ldapma01 slapd[8354]: conn=2122 op=2 UNBIND Oct 20 09:47:18 ldapma01 slapd[8354]: conn=2123 fd=19 closed Oct 20 09:47:18 ldapma01 slapd[8354]: slap_graduate_commit_csn: removing 0x1218c070 20091020074718.707969Z#000000#000#000000 Oct 20 09:47:18 ldapma01 slapd[8354]: conn=2122 fd=15 closed slave.log: Oct 20 09:47:18 ldapsl01 slapd[11608]: syncrepl_entry: rid=467 LDAP_RES_SEARCH_ENTRY(LDAP_SYNC_ADD) Oct 20 09:47:18 ldapsl01 slapd[11608]: syncrepl_entry: rid=467 be_search (0) Oct 20 09:47:18 ldapsl01 slapd[11608]: syncrepl_entry: rid=467 cn=15,ou=slamdtest,o=example,c=de Oct 20 09:47:18 ldapsl01 slapd[11608]: slap_queue_csn: queing 0x12159830 20091020074718.210361Z#000000#000#000000 Oct 20 09:47:18 ldapsl01 slapd[11608]: slap_graduate_commit_csn: removing 0x120f6b20 20091020074718.210361Z#000000#000#000000 Oct 20 09:47:18 ldapsl01 slapd[11608]: syncrepl_entry: rid=467 be_add cn=15,ou=slamdtest,o=example,c=de (0) Oct 20 09:47:18 ldapsl01 slapd[11608]: slap_queue_csn: queing 0x12159830 20091020074718.210361Z#000000#000#000000 Oct 20 09:47:18 ldapsl01 slapd[11608]: slap_graduate_commit_csn: removing 0x120f6b20 20091020074718.210361Z#000000#000#000000 Oct 20 09:47:18 ldapsl01 slapd[11608]: do_syncrep2: cookie= Oct 20 09:47:18 ldapsl01 slapd[11608]: syncrepl_entry: rid=467 LDAP_RES_SEARCH_ENTRY(LDAP_SYNC_ADD) Oct 20 09:47:18 ldapsl01 slapd[11608]: syncrepl_entry: rid=467 be_search (0) Oct 20 09:47:18 ldapsl01 slapd[11608]: syncrepl_entry: rid=467 cn=17,ou=slamdtest,o=example,c=de Oct 20 09:47:18 ldapsl01 slapd[11608]: syncrepl_entry: rid=467 be_add cn=17,ou=slamdtest,o=example,c=de (0) Oct 20 09:47:18 ldapsl01 slapd[11608]: do_syncrep2: cookie=rid=467,csn=20091020074718.732501Z#000000#000#000000 Oct 20 09:47:18 ldapsl01 slapd[11608]: syncrepl_entry: rid=467 LDAP_RES_SEARCH_ENTRY(LDAP_SYNC_ADD) Oct 20 09:47:18 ldapsl01 slapd[11608]: syncrepl_entry: rid=467 be_search (0) Oct 20 09:47:18 ldapsl01 slapd[11608]: syncrepl_entry: rid=467 cn=18,ou=slamdtest,o=example,c=de Oct 20 09:47:18 ldapsl01 slapd[11608]: slap_queue_csn: queing 0x12159830 20091020074718.732501Z#000000#000#000000 Oct 20 09:47:18 ldapsl01 slapd[11608]: slap_graduate_commit_csn: removing 0x12142e30 20091020074718.732501Z#000000#000#000000 Oct 20 09:47:18 ldapsl01 slapd[11608]: syncrepl_entry: rid=467 be_add cn=18,ou=slamdtest,o=example,c=de (0) Oct 20 09:47:18 ldapsl01 slapd[11608]: slap_queue_csn: queing 0x12159830 20091020074718.732501Z#000000#000#000000 Oct 20 09:47:18 ldapsl01 slapd[11608]: slap_graduate_commit_csn: removing 0x12142e30 20091020074718.732501Z#000000#000#000000 Oct 20 09:47:18 ldapsl01 slapd[11608]: do_syncrep2: cookie=rid=467,csn=20091020074718.719682Z#000000#000#000000 Oct 20 09:47:18 ldapsl01 slapd[11608]: do_syncrep2: rid=467 CSN too old, ignoring 20091020074718.719682Z#000000#000#000000 Oct 20 09:47:19 ldapsl01 slapd[11608]: do_syncrep2: cookie=rid=467,csn=20091020074719.251457Z#000000#000#000000 Oct 20 09:47:19 ldapsl01 slapd[11608]: syncrepl_entry: rid=467 LDAP_RES_SEARCH_ENTRY(LDAP_SYNC_ADD) Oct 20 09:47:19 ldapsl01 slapd[11608]: syncrepl_entry: rid=467 be_search (0) Oct 20 09:47:19 ldapsl01 slapd[11608]: syncrepl_entry: rid=467 cn=19,ou=slamdtest,o=example,c=de Oct 20 09:47:19 ldapsl01 slapd[11608]: slap_queue_csn: queing 0x121789b0 20091020074719.251457Z#000000#000#000000 Oct 20 09:47:19 ldapsl01 slapd[11608]: slap_graduate_commit_csn: removing 0x120f6b20 20091020074719.251457Z#000000#000#000000 Oct 20 09:47:19 ldapsl01 slapd[11608]: syncrepl_entry: rid=467 be_add cn=19,ou=slamdtest,o=example,c=de (0) Oct 20 09:47:19 ldapsl01 slapd[11608]: slap_queue_csn: queing 0x121789b0 20091020074719.251457Z#000000#000#000000 Oct 20 09:47:19 ldapsl01 slapd[11608]: slap_graduate_commit_csn: removing 0x120f6b20 20091020074719.251457Z#000000#000#000000 DELETE: master.log: Oct 20 09:53:25 ldapma01 slapd[8354]: conn=3574 fd=15 ACCEPT from IP=172.26.248.57:55919 (IP=0.0.0.0:389) Oct 20 09:53:25 ldapma01 slapd[8354]: conn=3574 op=0 BIND dn="uid=ladmin,ou=verwaltung,o=example,c=de" method=128 Oct 20 09:53:25 ldapma01 slapd[8354]: conn=3574 op=0 BIND dn="uid=ladmin,ou=Verwaltung,o=example,c=de" mech=SIMPLE ssf=0 Oct 20 09:53:25 ldapma01 slapd[8354]: conn=3574 op=0 RESULT tag=97 err=0 text= Oct 20 09:53:25 ldapma01 slapd[8354]: conn=3574 op=1 DEL dn="cn=460,ou=slamdtest,o=example,c=de" Oct 20 09:53:25 ldapma01 slapd[8354]: slap_queue_csn: queing 0x9c6e7db8 20091020075325.717023Z#000000#000#000000 Oct 20 09:53:25 ldapma01 slapd[8354]: conn=3574 op=1 RESULT tag=107 err=0 text= Oct 20 09:53:25 ldapma01 slapd[8354]: slap_graduate_commit_csn: removing 0xa320a6d8 20091020075325.717023Z#000000#000#000000 Oct 20 09:53:25 ldapma01 slapd[8354]: conn=3574 op=2 UNBIND Oct 20 09:53:25 ldapma01 slapd[8354]: syncprov_sendresp: cookie=rid=330,csn=20091020075325.717023Z#000000#000#000000 Oct 20 09:53:25 ldapma01 slapd[8354]: syncprov_sendresp: cookie=rid=332,csn=20091020075325.717023Z#000000#000#000000 Oct 20 09:53:25 ldapma01 slapd[8354]: syncprov_sendresp: cookie=rid=467,csn=20091020075325.717023Z#000000#000#000000 Oct 20 09:53:25 ldapma01 slapd[8354]: syncprov_sendresp: cookie=rid=466,csn=20091020075325.717023Z#000000#000#000000 Oct 20 09:53:25 ldapma01 slapd[8354]: syncprov_sendresp: cookie=rid=442,csn=20091020075325.717023Z#000000#000#000000 Oct 20 09:53:25 ldapma01 slapd[8354]: conn=3574 fd=15 closed Oct 20 09:53:25 ldapma01 slapd[8354]: conn=3575 fd=15 ACCEPT from IP=172.26.248.57:55920 (IP=0.0.0.0:389) Oct 20 09:53:25 ldapma01 slapd[8354]: conn=3575 op=0 BIND dn="uid=ladmin,ou=verwaltung,o=example,c=de" method=128 Oct 20 09:53:25 ldapma01 slapd[8354]: conn=3575 op=0 BIND dn="uid=ladmin,ou=Verwaltung,o=example,c=de" mech=SIMPLE ssf=0 Oct 20 09:53:25 ldapma01 slapd[8354]: conn=3575 op=0 RESULT tag=97 err=0 text= Oct 20 09:53:25 ldapma01 slapd[8354]: conn=3575 op=1 DEL dn="cn=461,ou=slamdtest,o=example,c=de" Oct 20 09:53:25 ldapma01 slapd[8354]: slap_queue_csn: queing 0x983f6db8 20091020075325.887748Z#000000#000#000000 Oct 20 09:53:25 ldapma01 slapd[8354]: conn=3576 fd=20 ACCEPT from IP=172.26.248.57:55921 (IP=0.0.0.0:389) Oct 20 09:53:25 ldapma01 slapd[8354]: conn=3576 op=0 BIND dn="uid=ladmin,ou=verwaltung,o=example,c=de" method=128 Oct 20 09:53:25 ldapma01 slapd[8354]: conn=3576 op=0 BIND dn="uid=ladmin,ou=Verwaltung,o=example,c=de" mech=SIMPLE ssf=0 Oct 20 09:53:25 ldapma01 slapd[8354]: conn=3576 op=0 RESULT tag=97 err=0 text= Oct 20 09:53:25 ldapma01 slapd[8354]: conn=3576 op=1 DEL dn="cn=462,ou=slamdtest,o=example,c=de" Oct 20 09:53:25 ldapma01 slapd[8354]: slap_queue_csn: queing 0x9b4e2db8 20091020075325.930710Z#000000#000#000000 Oct 20 09:53:25 ldapma01 slapd[8354]: syncprov_sendresp: cookie=rid=466,csn=20091020075325.887748Z#000000#000#000000 Oct 20 09:53:25 ldapma01 slapd[8354]: syncprov_sendresp: cookie=rid=442,csn=20091020075325.887748Z#000000#000#000000 Oct 20 09:53:25 ldapma01 slapd[8354]: conn=3576 op=1 RESULT tag=107 err=0 text= Oct 20 09:53:25 ldapma01 slapd[8354]: slap_graduate_commit_csn: removing 0xa320a6d8 20091020075325.930710Z#000000#000#000000 Oct 20 09:53:25 ldapma01 slapd[8354]: syncprov_sendresp: cookie=rid=466,csn=20091020075325.930710Z#000000#000#000000 Oct 20 09:53:25 ldapma01 slapd[8354]: syncprov_sendresp: cookie=rid=442,csn=20091020075325.930710Z#000000#000#000000 Oct 20 09:53:25 ldapma01 slapd[8354]: syncprov_sendresp: cookie=rid=467,csn=20091020075325.930710Z#000000#000#000000 Oct 20 09:53:25 ldapma01 slapd[8354]: syncprov_sendresp: cookie=rid=330,csn=20091020075325.930710Z#000000#000#000000 Oct 20 09:53:25 ldapma01 slapd[8354]: syncprov_sendresp: cookie=rid=332,csn=20091020075325.930710Z#000000#000#000000 Oct 20 09:53:25 ldapma01 slapd[8354]: conn=3576 op=2 UNBIND Oct 20 09:53:25 ldapma01 slapd[8354]: conn=3576 fd=20 closed Oct 20 09:53:25 ldapma01 slapd[8354]: syncprov_sendresp: cookie=rid=467,csn=20091020075325.887748Z#000000#000#000000 Oct 20 09:53:25 ldapma01 slapd[8354]: syncprov_sendresp: cookie=rid=330,csn=20091020075325.887748Z#000000#000#000000 Oct 20 09:53:25 ldapma01 slapd[8354]: syncprov_sendresp: cookie=rid=332,csn=20091020075325.887748Z#000000#000#000000 Oct 20 09:53:25 ldapma01 slapd[8354]: conn=3575 op=1 RESULT tag=107 err=0 text= Oct 20 09:53:25 ldapma01 slapd[8354]: slap_graduate_commit_csn: removing 0xa320a5e8 20091020075325.887748Z#000000#000#000000 Oct 20 09:53:25 ldapma01 slapd[8354]: conn=3575 op=2 UNBIND Oct 20 09:53:25 ldapma01 slapd[8354]: conn=3575 fd=15 closed Oct 20 09:53:26 ldapma01 slapd[8354]: conn=3577 fd=15 ACCEPT from IP=172.26.248.57:55922 (IP=0.0.0.0:389) Oct 20 09:53:26 ldapma01 slapd[8354]: conn=3577 op=0 BIND dn="uid=ladmin,ou=verwaltung,o=example,c=de" method=128 Oct 20 09:53:26 ldapma01 slapd[8354]: conn=3577 op=0 BIND dn="uid=ladmin,ou=Verwaltung,o=example,c=de" mech=SIMPLE ssf=0 Oct 20 09:53:26 ldapma01 slapd[8354]: conn=3577 op=0 RESULT tag=97 err=0 text= Oct 20 09:53:26 ldapma01 slapd[8354]: conn=3577 op=1 DEL dn="cn=463,ou=slamdtest,o=example,c=de" Oct 20 09:53:26 ldapma01 slapd[8354]: slap_queue_csn: queing 0xa24fbdb8 20091020075326.244684Z#000000#000#000000 Oct 20 09:53:26 ldapma01 slapd[8354]: conn=3577 op=1 RESULT tag=107 err=0 text= Oct 20 09:53:26 ldapma01 slapd[8354]: slap_graduate_commit_csn: removing 0xa320edb0 20091020075326.244684Z#000000#000#000000 Oct 20 09:53:26 ldapma01 slapd[8354]: syncprov_sendresp: cookie=rid=466,csn=20091020075326.244684Z#000000#000#000000 Oct 20 09:53:26 ldapma01 slapd[8354]: syncprov_sendresp: cookie=rid=442,csn=20091020075326.244684Z#000000#000#000000 Oct 20 09:53:26 ldapma01 slapd[8354]: syncprov_sendresp: cookie=rid=467,csn=20091020075326.244684Z#000000#000#000000 Oct 20 09:53:26 ldapma01 slapd[8354]: syncprov_sendresp: cookie=rid=330,csn=20091020075326.244684Z#000000#000#000000 Oct 20 09:53:26 ldapma01 slapd[8354]: syncprov_sendresp: cookie=rid=332,csn=20091020075326.244684Z#000000#000#000000 Oct 20 09:53:26 ldapma01 slapd[8354]: conn=3577 op=2 UNBIND Oct 20 09:53:26 ldapma01 slapd[8354]: conn=3577 fd=15 closed slave.log: Oct 20 09:53:25 ldapsl01 slapd[11608]: do_syncrep2: cookie=rid=467,csn=20091020075325.717023Z#000000#000#000000 Oct 20 09:53:25 ldapsl01 slapd[11608]: syncrepl_entry: rid=467 LDAP_RES_SEARCH_ENTRY(LDAP_SYNC_DELETE) Oct 20 09:53:25 ldapsl01 slapd[11608]: syncrepl_entry: rid=467 be_search (0) Oct 20 09:53:25 ldapsl01 slapd[11608]: syncrepl_entry: rid=467 cn=460,ou=slamdtest,o=example,c=de Oct 20 09:53:25 ldapsl01 slapd[11608]: slap_queue_csn: queing 0x1210a9d8 20091020075325.717023Z#000000#000#000000 Oct 20 09:53:25 ldapsl01 slapd[11608]: slap_graduate_commit_csn: removing 0x122416d0 20091020075325.717023Z#000000#000#000000 Oct 20 09:53:25 ldapsl01 slapd[11608]: syncrepl_entry: rid=467 be_delete cn=460,ou=slamdtest,o=example,c=de (0) Oct 20 09:53:25 ldapsl01 slapd[11608]: slap_queue_csn: queing 0x1210a9d8 20091020075325.717023Z#000000#000#000000 Oct 20 09:53:25 ldapsl01 slapd[11608]: slap_graduate_commit_csn: removing 0x12238750 20091020075325.717023Z#000000#000#000000 Oct 20 09:53:25 ldapsl01 slapd[11608]: do_syncrep2: cookie=rid=467,csn=20091020075325.930710Z#000000#000#000000 Oct 20 09:53:25 ldapsl01 slapd[11608]: syncrepl_entry: rid=467 LDAP_RES_SEARCH_ENTRY(LDAP_SYNC_DELETE) Oct 20 09:53:25 ldapsl01 slapd[11608]: syncrepl_entry: rid=467 be_search (0) Oct 20 09:53:25 ldapsl01 slapd[11608]: syncrepl_entry: rid=467 cn=462,ou=slamdtest,o=example,c=de Oct 20 09:53:25 ldapsl01 slapd[11608]: slap_queue_csn: queing 0x1222b320 20091020075325.930710Z#000000#000#000000 Oct 20 09:53:25 ldapsl01 slapd[11608]: slap_graduate_commit_csn: removing 0x12238750 20091020075325.930710Z#000000#000#000000 Oct 20 09:53:25 ldapsl01 slapd[11608]: syncrepl_entry: rid=467 be_delete cn=462,ou=slamdtest,o=example,c=de (0) Oct 20 09:53:25 ldapsl01 slapd[11608]: slap_queue_csn: queing 0x1222b320 20091020075325.930710Z#000000#000#000000 Oct 20 09:53:25 ldapsl01 slapd[11608]: slap_graduate_commit_csn: removing 0x12240cf0 20091020075325.930710Z#000000#000#000000 Oct 20 09:53:25 ldapsl01 slapd[11608]: do_syncrep2: cookie=rid=467,csn=20091020075325.887748Z#000000#000#000000 Oct 20 09:53:25 ldapsl01 slapd[11608]: do_syncrep2: rid=467 CSN too old, ignoring 20091020075325.887748Z#000000#000#000000 Oct 20 09:53:26 ldapsl01 slapd[11608]: do_syncrep2: cookie=rid=467,csn=20091020075326.244684Z#000000#000#000000 Oct 20 09:53:26 ldapsl01 slapd[11608]: syncrepl_entry: rid=467 LDAP_RES_SEARCH_ENTRY(LDAP_SYNC_DELETE) Oct 20 09:53:26 ldapsl01 slapd[11608]: syncrepl_entry: rid=467 be_search (0) Oct 20 09:53:26 ldapsl01 slapd[11608]: syncrepl_entry: rid=467 cn=463,ou=slamdtest,o=example,c=de Oct 20 09:53:26 ldapsl01 slapd[11608]: slap_queue_csn: queing 0x12235c68 20091020075326.244684Z#000000#000#000000 Oct 20 09:53:26 ldapsl01 slapd[11608]: slap_graduate_commit_csn: removing 0x12240cf0 20091020075326.244684Z#000000#000#000000 Oct 20 09:53:26 ldapsl01 slapd[11608]: syncrepl_entry: rid=467 be_delete cn=463,ou=slamdtest,o=example,c=de (0) Oct 20 09:53:26 ldapsl01 slapd[11608]: slap_queue_csn: queing 0x12235c68 20091020075326.244684Z#000000#000#000000 Oct 20 09:53:26 ldapsl01 slapd[11608]: slap_graduate_commit_csn: removing 0x12139a10 20091020075326.244684Z#000000#000#000000 -- Thanks Christoph -- Vorstand/Board of Management: Dr. Bernd Finkbeiner, Dr. Roland Niemeier, Dr. Arno Steitz, Dr. Ingrid Zech Vorsitzender des Aufsichtsrats/ Chairman of the Supervisory Board: Michel Lepert Sitz/Registered Office: Tuebingen Registergericht/Registration Court: Stuttgart Registernummer/Commercial Register No.: HRB 382196

3 3

MirrorMode and chaining - are slaves needed?
by Ryan Steele 20 Oct '09

20 Oct '09

Hi folks, I'm in the process of setting up about six nodes, and tossing around the idea of having either 2 masters in MirrorMode (traffic to the "active" master is managed externally) with 4 slaves (each of whom will refer their writes to the active master). I'm automating some of the setup, and in an effort to simplify the configuration, was wondering if I might be better served by simply having 6 masters with an identical configuration, each of which refer their writes to the active master (a separate IP/hostname on a virtual interface on one of the masters). So, the question becomes, 'are there any downsides I'm not aware of?' It seems to me that the advantage with the 6 masters is that, aside from the consolidation of configs for the automated setup, I now have 6 write-capable nodes instead of 2. And, provided I chain the writes to the active master, I shouldn't have to worry about incompatible writes/partitioning. Any thoughts, advice, recommendations? Thanks! -Ryan

3 3

Re: MirrorMode and chaining - are slaves needed?
by Gavin Henry 20 Oct '09

20 Oct '09

----- "Ryan Steele" <ryans(a)aweber.com> wrote: > Gavin Henry wrote: > > ----- "Ryan Steele" <ryans(a)aweber.com> wrote: > > > >> Hi folks, > >> > >> I'm in the process of setting up about six nodes, and tossing > around > >> the idea of having either 2 masters in MirrorMode > >> (traffic to the "active" master is managed externally) with 4 > slaves > >> (each of whom will refer their writes to the active > >> master). I'm automating some of the setup, and in an effort to > >> simplify the configuration, was wondering if I might be > >> better served by simply having 6 masters with an identical > >> configuration, each of which refer their writes to the active > >> master (a separate IP/hostname on a virtual interface on one of > the > >> masters). > >> > >> So, the question becomes, 'are there any downsides I'm not aware > of?' > >> It seems to me that the advantage with the 6 > >> masters is that, aside from the consolidation of configs for the > >> automated setup, I now have 6 write-capable nodes > >> instead of 2. And, provided I chain the writes to the active > master, > >> I shouldn't have to worry about incompatible > >> writes/partitioning. Any thoughts, advice, recommendations? > Thanks! > > > > If you have 6 masters you don't need to chain anything as that is > Multi Master. > > > > I'm confused as to why you are chaining from a master to an active > master. You should have > > either two MirrorMode nodes (with management) and chaining slaves or > full Multi Master. > > I want to use MirrorMode, but between six nodes instead of two (the > example in the Admin Guide uses three, so I figured > using more than just two nodes was fine). As such, I need an active > master to ensure that two masters don't write to > the same entry or entries at (or near) the same time and cause a > conflict/partition. Sorry Ryan, but I think you misunderstand MirrorMode. MirrorMode is Active-Active Hot-standby. It's designed for just *two* nodes. The example in the admin guide is for full Multi-Master, but only showing three masters. Anything more that two is Multi-Master. > I figured that having six masters in MirrorMode, instead of two > masters and four slaves, would allow me to cut down on > configuration while boosting my redundancy. I would use chaining on > all of them to both keep the configs identical > (less management overhead) and ensure that I don't run in to the > aforementioned conflict scenarios. Is there anything > I've failed to consider in deciding that using six masters in > MirrorMode is more desirable than having two masters in > MirrorMode with four slaves? See above. If you have 6 Multi-Master and replicate cn=config and the rest of the data, you will have your desired outcome. > > The way you've described above isn't very clear and sounds messy. > What your clients/apps need > > from the slaves? What is the usage pattern etc. > > I thought it sounded more simple - six masters with identical > configurations (both cn=config and backend database > replicated via identical syncprov/syncrepl configurations on each > node), with all writes being directed to the active > master; the chaining just guarantees that any writes erroneously sent > to an inactive master would be forwarded on to the > active master. They handle this all themselves via SyncRepl when in Multimaster mode. As all writes have to go to all masters. > In contrast, with the two masters and four slaves, the two masters > must share syncprov/syncrepl configs and replicate > cn=config and backend data to and from each other, while replicating > the backend to the slaves; the six slaves would in > turn need entirely separate syncprov/syncrepl configs since their > cn=config wouldn't be in MirrorMode, to ensure that > they replicate backend data to nobody and from the active master, and > because they'd still need to chain/refer writes to > the masters. Correct. > Does the above logic seem sound or flawed to you? Anything I've > glossed over or perhaps misunderstood? Thanks again > for all the advice and insight - I truly appreciate it! Just the terms MirrorMode and Multi-Master. Check out: http://www.openldap.org/doc/admin24/replication.html#MirrorMode%20replicati… http://www.openldap.org/doc/admin24/replication.html#N-Way%20Multi-Master%2… Thanks. -- Kind Regards, Gavin Henry. Managing Director. T +44 (0) 1224 279484 M +44 (0) 7930 323266 F +44 (0) 1224 824887 E ghenry(a)suretecsystems.com Open Source. Open Solutions(tm). http://www.suretecsystems.com/ Suretec Systems is a limited company registered in Scotland. Registered number: SC258005. Registered office: 24 Cormack Park, Rothienorman, Inverurie, Aberdeenshire, AB51 8GL. Subject to disclaimer at http://www.suretecgroup.com/disclaimer.html

2 1

Re: ACL Question 'write stop' 'write break'
by Aaron Richton 19 Oct '09

19 Oct '09

Please keep replies on the list. On Mon, 19 Oct 2009, Edward Capriolo wrote: [...cut...] > As you have said .*managed people are never able to auth, one that > rule is put in place. So If I understand you correctly I should do > this: > > access to dn.regex="mail=.*.managed(a)jointhegrid.com,ou=user,ou=jointhegrid.com,o=jointhegrid,c=US" > attrs=userPassword,accountstatus > by dn="mail=john(a)jointhegrid.com,ou=user,ou=jointhegrid.com,o=jointhegrid,c=US" > write stop > by dn="mail=sara(a)jointhegrid.com,ou=user,ou=jointhegrid,o=jointhegrid,c=US" > write stop > by * none break > access to attr=userPassword > by self write > by anonymous auth > by dn="mail=samba(a)jointhegrid.com,ou=user,ou=jointhegrid.com,o=jointhegrid,c=US" > read > by dn="mail=samba(a)jointhegrid-inc.com,ou=user,ou=jointhegrid-inc.com,o=jointhegrid,c=US" > read > by * none > > ? Sure, that's a reasonable first move, if I'm understanding your desires correctly. Personally I like being very very very explicit in my ACLs, so I might actually write out dn.exact and put the * in "access to attr=userPassword." But you can worry about that in version 5...

1 0

ACL Question 'write stop' 'write break'
by Edward Capriolo 19 Oct '09

19 Oct '09

Hello all, We are currently migrating from a master-slave, to a multi-master setup. All went well except for the fact that the access on the old master node was more liberal then the access on the slave node. As a result some applications were able to use this to their advantage and now are not working quite correctly when each node is a read write master. here is my configuration: #access to dn.regex="mail=.*.managed(a)jointhegrid.com,ou=user,ou=jointhegrid.com,o=jointhegrid,c=US" # attrs=userPassword,accountstatus # by dn="mail=john(a)jointhegrid.com,ou=user,ou=jointhegrid.com,o=jointhegrid,c=US" write break # by dn="mail=sara(a)jointhegrid.com,ou=user,ou=jointhegrid,o=jointhegrid,c=US" write break access to attr=userPassword by self write by anonymous auth by dn="mail=samba(a)jointhegrid.com,ou=user,ou=jointhegrid.com,o=jointhegrid,c=US" read by dn="mail=samba(a)jointhegrid-inc.com,ou=user,ou=jointhegrid-inc.com,o=jointhegrid,c=US" read by * none access to attrs=sambaLMPassword,sambaNTPassword by dn="mail=samba(a)jointhegrid.com,ou=user,ou=jointhegrid.com,o=jointhegrid,c=US" read by dn="mail=samba(a)jointhegrid-inc.com,ou=user,ou=jointhegrid-inc.com,o=jointhegrid,c=US" read by self write by * none access to * by dn="mail=samba(a)jointhegrid.com,ou=user,ou=jointhegrid.com,o=jointhegrid,c=US" write by dn="mail=samba(a)jointhegrid-inc.com,ou=user,ou=jointhegrid-inc.com,o=jointhegrid,c=US" write by dnattr=manager write by self write by users read by * none My problem is the top commented lines, these rules are to allow sara and john to administer all "mail=.*.managed" users. This worked fine in the past because no read queries hit the master, but now with multi-master "mail=.*.managed" users have no access to the directory. The old rule was # by dn="mail=sara(a)jointhegrid.com,ou=user,ou=jointhegrid,o=jointhegrid,c=US" write stop I also tried # by dn="mail=sara(a)jointhegrid.com,ou=user,ou=jointhegrid,o=jointhegrid,c=US" write break Which I was under the impression that "write break" would continue evaluation, but I do not understand how this is working. Can anyone help me with a suggestion for fixing this? Thank you!

3 3

memberOf does not Update on Group Modify
by Robert Henjes 16 Oct '09

16 Oct '09

Hi, I searched the lists and the Internet, but only a small portion of people seem to have the same problem. So I don't know, what's maybe wrong with my setup. One hint I found at: http://serverfault.com/questions/73213/how-do-i-configure-reverse-group-mem… I try to use the memberOf overlay in an openldap 2.4.11 (debian lenny) installation. This works so far. But if I'm going to modify a member attribute (add, delete, and modify) this change does not update the memberOf attributes returned. So in case of a deletion, the corresponding attribute memberOf still exists. Example: dn: cn=example,ou=management,ou=groups,dc=domain changetype: modify delete: member member: cn=my.name,o=uwue,ou=identities,dc=domain ldapsearch still returns: # ldapsearch -x -LLL -H ldaps://server:636 -b ou=identities,dc=domain -W -D cn=admin,dc=domain cn=my.name memberOf Enter LDAP Password: dn: cn=my.name,... memberOf: cn=xxx,ou=groups,dc=german-lab,dc=de memberOf: cn=xxy,ou=groups,dc=german-lab,dc=de memberOf: cn=example,ou=management,ou=groups,dc=german-lab,dc=de => Does not work - Restarting the slapd daemon does not help. - Using slapd.conf or cn=config makes no difference If I remove the complete groupOfNames object and reimport it as a ldif file, the new imported options are respected and correctly updated. But this behavior is very ugly in practice. So do you have any ideas, what to do? Thank you very much in advance, Robert Henjes -- Dipl.-Inform. Robert Henjes University of Wuerzburg, Institute of Computer Science, Chair of Distributed Systems (Informatik III), Am Hubland, 97074 Wuerzburg, Germany henjes(a)informatik.uni-wuerzburg.de Tel: +49 931 31-86652 Fax: +49 931 888-6632

2 3

Re: syncrepl push model with searchbase=""
by masarati＠aero.polimi.it 15 Oct '09

15 Oct '09

>>> Is it possible to achieve what we want using some other options? >> >> It might not be as soon as some internal searches rooted at <searchbase> >> with scope "base" need to be performed, because in this case they would >> actually return the rootDSE instead of the context entry of the database >> you're trying to replicate. This is a mere speculation, I haven't >> looked at the code yet. >> > > Apparently, my guess was correct. This is what the real consumer receives > from the syncrepl hidden in the provider at startup: > > conn=0 fd=14 ACCEPT from IP=127.0.0.1:34623 (IP=0.0.0.0:9012) > conn=0 op=0 BIND dn="cn=replicator" method=128 > conn=0 op=0 BIND dn="cn=replicator" mech=SIMPLE ssf=0 > conn=0 op=0 RESULT tag=97 err=0 text= > conn=0 op=1 SRCH base="" scope=0 deref=0 filter="(objectClass=*)" > conn=0 op=1 SRCH attr=contextCSN > conn=0 op=1 SEARCH RESULT tag=101 err=0 nentries=1 text= > > It searches for contextCSN in the root entry with base scope. Because of > the scope, the search actually gets to the rootDSE. What I see is that replication actually occurs; what really fails is: 1) reading the contextCSN from "" 2) writing the contextCSN to "" This is totally undesirable. Probably, having context info in a subentry of the context entry, as it was initially, would not have caused the problem. I suggest this issue is noted in the documentation of the "push" syncrepl. p.

2 1

Re: syncrepl push model with searchbase=""
by masarati＠aero.polimi.it 15 Oct '09

15 Oct '09

> ml+openldap(a)esmtp.org wrote: >> I'm trying to replace OpenLDAP 2.3.x with 2.4.18 (this project >> started before 2.4..19 came out). The old configuration uses slurpd, >> hence I have been tasked to set up a producer/consumer replication >> via syncrepl using the push model. I'm following the example from >> the admin guide but I have to modify the suffix/searchbase to be >> "" (as we allow pretty much anything in the DB). >> >> Doing this causes these log messages (loglevel 0x4000): >> >> on the master: >> do_syncrep2: rid=001 LDAP_RES_INTERMEDIATE - REFRESH_DELETE >> do_syncrep2: >> cookie=rid=001,sid=001,csn=20091014205621.868761Z#000000#001#000000 >> slap_queue_csn: queing 0x2aaaac001d90 >> 20091014205621.868761Z#000000#001#000000 >> null_callback : error code 0x35 >> syncrepl_updateCookie: rid=001 be_modify failed (53) >> >> on the consumer: >> slap_queue_csn: queing 0xd8e3a30 >> 20091014205621.868761Z#000000#001#000000 >> slap_graduate_commit_csn: removing 0xd8e3b00 >> 20091014205621.868761Z#000000#001#000000 >> conn=0 op=42 do_modify: root dse! >> >> This seems to be a problem with ``searchbase=""'' (in ``syncrepl''). >> If it is changed to ``searchbase="dc=com"'' (and matching ``suffix >> "dc=com"'' for ``database ldap'') the error does not occur. >> >> Is it possible to achieve what we want using some other options? > > It might not be as soon as some internal searches rooted at <searchbase> > with scope "base" need to be performed, because in this case they would > actually return the rootDSE instead of the context entry of the database > you're trying to replicate. This is a mere speculation, I haven't > looked at the code yet. > Apparently, my guess was correct. This is what the real consumer receives from the syncrepl hidden in the provider at startup: conn=0 fd=14 ACCEPT from IP=127.0.0.1:34623 (IP=0.0.0.0:9012) conn=0 op=0 BIND dn="cn=replicator" method=128 conn=0 op=0 BIND dn="cn=replicator" mech=SIMPLE ssf=0 conn=0 op=0 RESULT tag=97 err=0 text= conn=0 op=1 SRCH base="" scope=0 deref=0 filter="(objectClass=*)" conn=0 op=1 SRCH attr=contextCSN conn=0 op=1 SEARCH RESULT tag=101 err=0 nentries=1 text= It searches for contextCSN in the root entry with base scope. Because of the scope, the search actually gets to the rootDSE. Probably, we'd need a means to recognize searches with base="" and scope="base" that are actually directed to the context entry of a database rooted at "". This could be, say, the manageDSAit control (unless manageDSAit on a search for the rootDSE already has some specific meaning), or a specific control. This would probably solve your problem, and work for OpenLDAP-only setups. However, it would defeat the purpose of using push syncrepl with other vendors' products. p.

2 1

syncrepl push model with searchbase=""
by ml+openldap＠esmtp.org 15 Oct '09

15 Oct '09

I'm trying to replace OpenLDAP 2.3.x with 2.4.18 (this project started before 2.4..19 came out). The old configuration uses slurpd, hence I have been tasked to set up a producer/consumer replication via syncrepl using the push model. I'm following the example from the admin guide but I have to modify the suffix/searchbase to be "" (as we allow pretty much anything in the DB). Doing this causes these log messages (loglevel 0x4000): on the master: do_syncrep2: rid=001 LDAP_RES_INTERMEDIATE - REFRESH_DELETE do_syncrep2: cookie=rid=001,sid=001,csn=20091014205621.868761Z#000000#001#000000 slap_queue_csn: queing 0x2aaaac001d90 20091014205621.868761Z#000000#001#000000 null_callback : error code 0x35 syncrepl_updateCookie: rid=001 be_modify failed (53) on the consumer: slap_queue_csn: queing 0xd8e3a30 20091014205621.868761Z#000000#001#000000 slap_graduate_commit_csn: removing 0xd8e3b00 20091014205621.868761Z#000000#001#000000 conn=0 op=42 do_modify: root dse! This seems to be a problem with ``searchbase=""'' (in ``syncrepl''). If it is changed to ``searchbase="dc=com"'' (and matching ``suffix "dc=com"'' for ``database ldap'') the error does not occur. Is it possible to achieve what we want using some other options? Relevant parts from master slapd.conf: ---------------------------------------- database monitor database bdb directory /var/ldap/openldap-bdb suffix "" rootdn "cn=Manager" rootpw syncroni index entryCSN,entryUUID eq serverID 001 overlay syncprov database ldap hidden on suffix "" rootdn "cn=slapd-ldap" uri ldap://CONSUMER.HOST/ lastmod on restrict all acl-bind bindmethod=simple binddn="cn=Monitor" credentials=password syncrepl rid=001 provider=ldap://localhost/ bindmethod=simple binddn="cn=Manager" credentials=syncroni scope=children searchbase="" filter="(objectClass=*)" type=refreshAndPersist retry="5 2 300 2" ---------------------------------------- relevant parts from consumer slapd.conf: ---------------------------------------- database monitor rootdn "cn=Monitor" rootpw password database bdb directory /var/ldap/openldap-bdb suffix "" index entryUUID eq access to dn.subtree="" attrs=hasSubordinates by dn.exact="cn=Monitor" none by * read access to dn.subtree="" by dn.exact="cn=Monitor" write by * read updatedn "cn=Monitor" updateref ldap://MASTER.HOST/ ----------------------------------------

3 7

performance very differently for two hosts that are configured identical
by Zhang Weiwu 15 Oct '09

15 Oct '09

We have a development server 'emerson' with roughly one third of the performance of our productional server 'bossdog', it runs ldap query 10 times faster than the productional server. I checked everything I can to find out the difference, it seems both are equally configured. Test method: emerson:~# time for (( i=0; i<100; i++)); do ldapsearch -xD cn=manager,dc=eoa,dc=cn -w masked -b ou=contacts,ou=realss.com,dc=eoa,dc=cn '(uidNumber=7)' dn; done; [snip] # zhangweiwu, contacts, realss.com, eoa.cn dn: uid=zhangweiwu,ou=contacts,ou=realss.com,dc=eoa,dc=cn # search result search: 2 result: 0 Success # numResponses: 2 # numEntries: 1 real 0m1.047s user 0m0.320s sys 0m0.352s bossdog:~# time for (( i=0; i<100; i++)); do ldapsearch -xD cn=manager,dc=eoa,dc=cn -w masked -b ou=contacts,ou=realss.com,dc=eoa,dc=cn '(uidNumber=7)' dn; done; [snip] real 0m41.790s user 0m0.232s sys 0m0.464s What I have compared: 1. Both server uses Debian Lenney 2. Both server have same DB_CONFIG in /var/lib/ldap 3. Both server have same ACL settings. In fact we tried to reduce the ACL setting on the slow preforming productional server without improvement result. 4. Both server uses bdb 5. Compare syslog at log level 256 both server produce same log messages 6. The productional server shows harddisk is twice as fast as development server (hdparm), free memory more than the development server, and its dual-core xeon cpu should outperform the VIA CPU used in the development server, yet slower. The productional server average load is 0.5 which is not high for dual-CPU (with hyperthreading display as 4 CPUs to Linux). 7. Productional server DB is then re-built (by rm -rf & slapadd) without noticeable change in performance. This performance difference resulted the productional server user interface much slower than user's patience. What would you check further in this case? Thanks in advance!

2 5

2024

2023

2022

2021

2020

2019

2018

2017

2016

2015

2014

2013

2012

2011

2010

2009

2008

2007

2006

openldap-software October 2009