--On Sunday, April 23, 2017 12:38 AM +0000 Jesper Grøndahl grondahl@ruc.dk wrote:
Our log level is stats and sync.
The logs look like this, for the user being modified
nonpresent_callback: rid=005 present UUID 528929d6-acaa-1036-922a-a3f5c9285d9d, dn uid=xxx,ou=users,dc=ruc,dc=dk Entry uid=xxx,ou=users,dc=ruc,dc=dk CSN 20170406140323.504919Z#000000#002#000000 greater than snapshot 20170403102309.253881Z#000000#002#000000
It would appear you have serious issues with your installation, since the CSNs are off by 3 days. I would note that 2.4.40 is not stable for MMR as well. I would ensure you aren't suffering from clock skew across your servers, and upgrade to the current OpenLDAP release as well.
--Quanah
--
Quanah Gibson-Mount Product Architect Symas Corporation Packaged, certified, and supported LDAP solutions powered by OpenLDAP: http://www.symas.com
Hi Quanah
Thanks for the response.
On 04/26/2017 05:16 PM, Quanah Gibson-Mount wrote:
--On Sunday, April 23, 2017 12:38 AM +0000 Jesper Grøndahl grondahl@ruc.dk wrote:
Our log level is stats and sync.
The logs look like this, for the user being modified
nonpresent_callback: rid=005 present UUID 528929d6-acaa-1036-922a-a3f5c9285d9d, dn uid=xxx,ou=users,dc=ruc,dc=dk Entry uid=xxx,ou=users,dc=ruc,dc=dk CSN 20170406140323.504919Z#000000#002#000000 greater than snapshot 20170403102309.253881Z#000000#002#000000
It would appear you have serious issues with your installation, since the CSNs are off by 3 days. I would note that 2.4.40 is not stable for MMR as well. I would ensure you aren't suffering from clock skew across your servers, and upgrade to the current OpenLDAP release as well.
--Quanah
There was no time skew across the servers.
But I tried to make three new machines to make sure that they were setup exactly the same way. I installed openldap 2.4.44 (from Debian Jessie backports) and checked that there was no time skew across them. Now I have loaded only a small group of users and the replication seems to work fine, and I guess the ouput from a modification of an object looks okay...
Provider: May 2 12:30:52 ldap1-test slapd[592]: slap_queue_csn: queueing 0x7f3f64104210 20170502103052.537391Z#000000#001#000000 May 2 12:30:52 ldap1-test slapd[592]: slap_graduate_commit_csn: removing 0x7f3f64104210 20170502103052.537391Z#000000#001#000000
One of the consumers: May 2 12:31:01 ldap2-test slapd[529]: syncrepl_message_to_entry: rid=004 DN: uid=bbb,ou=users,dc=ruc,dc=dk, UUID: 7b70b260-c1e0-1036-9931-077f97b008c3 May 2 12:31:01 ldap2-test slapd[529]: syncrepl_entry: rid=004 LDAP_RES_SEARCH_ENTRY(LDAP_SYNC_ADD) May 2 12:31:01 ldap2-test slapd[529]: syncrepl_entry: rid=004 be_search (0) May 2 12:31:01 ldap2-test slapd[529]: syncrepl_entry: rid=004 uid=bbb,ou=users,dc=ruc,dc=dk May 2 12:31:01 ldap2-test slapd[529]: do_syncrep2: rid=006 LDAP_RES_SEARCH_RESULT May 2 12:31:01 ldap2-test slapd[529]: syncrepl_entry: rid=004 be_modify uid=bbb,ou=users,dc=ruc,dc=dk (0) May 2 12:31:01 ldap2-test slapd[529]: do_syncrep2: rid=004 LDAP_RES_SEARCH_RESULT May 2 12:31:01 ldap2-test slapd[529]: do_syncrep2: rid=004 cookie=rid=004,sid=001,csn=20170502103052.537391Z#000000#001#000000;20170502081309.136359Z#000000#002#000000;20170502084407.568193Z#000000#003#000000 May 2 12:31:01 ldap2-test slapd[529]: nonpresent_callback: rid=004 present UUID 0aad8da8-c084-1036-8e9e-97a1769fcc36, dn dc=ruc,dc=dk May 2 12:31:01 ldap2-test slapd[529]: nonpresent_callback: rid=004 present UUID df369d04-c083-1036-9c8b-2f6b71d13f6f, dn cn=admin,dc=ruc,dc=dk May 2 12:31:01 ldap2-test slapd[529]: nonpresent_callback: rid=004 present UUID 7b6dcc26-c1e0-1036-992a-077f97b008c3, dn ou=users,dc=ruc,dc=dk May 2 12:31:01 ldap2-test slapd[529]: nonpresent_callback: rid=004 present UUID 7b70415e-c1e0-1036-9930-077f97b008c3, dn uid=aaa,ou=users,dc=ruc,dc=dk May 2 12:31:01 ldap2-test slapd[529]: nonpresent_callback: rid=004 present UUID 7b70b260-c1e0-1036-9931-077f97b008c3, dn uid=bbb,ou=users,dc=ruc,dc=dk May 2 12:31:01 ldap2-test slapd[529]: nonpresent_callback: rid=004 present UUID 7b714ed2-c1e0-1036-9932-077f97b008c3, dn uid=ccc,ou=users,dc=ruc,dc=dk May 2 12:31:01 ldap2-test slapd[529]: nonpresent_callback: rid=004 present UUID 7b71efd6-c1e0-1036-9933-077f97b008c3, dn uid=ddd,ou=users,dc=ruc,dc=dk May 2 12:31:01 ldap2-test slapd[529]: slap_queue_csn: queueing 0x7ff63c115350 20170502103052.537391Z#000000#001#000000 May 2 12:31:01 ldap2-test slapd[529]: slap_graduate_commit_csn: removing 0x7ff63c115350 20170502103052.537391Z#000000#001#000000
However, as you can see I still get the "nonpresent_callback" lines for each user. I can see that if you set "olcSpNoPresent: TRUE" in the syncprov overlay entry the lines disappear. But I can understand that it should only be done if you have an acceslog.
So is it really necessary to go through all the objects in the database every time you modify a single record when you have a mmr setup? It just seems like a lot of information written to the log and a lot of work every time a single record is modified.
-- Jesper
openldap-technical@openldap.org