Running on 2.4.39 centos 6.4 in MMR setup ( 4 servers ). 001 is the provider that was being written to at the time. The log is from 001. Could you advise whether my understanding of the log is correct?
synrepl consumer on serverID=001 is polling syncrepl provider on serverID=001 and 003 and gets the CSN that is older that its own. We were doing a lot of writes during this time and there were cmp -1 104480 or simiar entries in the log. I had similar issue in the past while running 2.4.37 and it crashed slapd at that time but it didnt this time. The CSN were all synced at the end without any issue.
Could you advise what could be causing this?
Oct 8 20:36:50 servername slapd[58097]: srs csn 20141008181030.452659Z#000000#001#000000
Oct 8 20:36:50 servername slapd[58097]: log csn 20140723214017.586869Z#000000#001#000000
Oct 8 20:36:50 servername slapd[58097]: cmp -1, too old
Oct 8 20:36:50 servername slapd[58097]: log csn 20140723214017.847644Z#000000#001#000000
Oct 8 20:36:50 servername slapd[58097]: cmp -1, too old
Oct 8 20:36:50 servername slapd[58097]: log csn 20140723214122.276227Z#000000#001#000000
Oct 8 20:36:50 servername slapd[58097]: cmp -1, too old
Oct 8 20:36:50 servername slapd[58097]: log csn 20140723214515.997173Z#000000#001#000000
Oct 8 20:36:50 servername slapd[58097]: cmp -1, too old
Oct 8 20:36:50 servername slapd[58097]: log csn 20140723214734.650752Z#000000#001#000000
Oct 8 20:36:50 servername slapd[58097]: log csn 20140723220152.569135Z#000000#003#000000
Oct 8 20:36:50 servername slapd[58097]: cmp -1, too old
Oct 8 20:36:50 servername slapd[58097]: log csn 20140723220328.184724Z#000000#001#000000
Oct 8 20:36:50 servername slapd[58097]: cmp -1, too old
Oct 8 20:36:50 servername slapd[58097]: log csn 20140723222016.864642Z#000000#001#000000
Oct 8 20:36:50 servername slapd[58097]: cmp -1, too old
Oct 8 20:36:50 servername slapd[58097]: log csn 20140723232832.307038Z#000000#003#000000
Oct 8 20:36:50 servername slapd[58097]: cmp -1, too old
Oct 8 20:36:50 servername slapd[58097]: log csn 20140723232958.001298Z#000000#003#000000
Daniel Jung wrote:
Running on 2.4.39 centos 6.4 in MMR setup ( 4 servers ). 001 is the provider that was being written to at the time. The log is from 001. Could you advise whether my understanding of the log is correct?
synrepl consumer on serverID=001 is polling syncrepl provider on serverID=001 and 003 and gets the CSN that is older that its own.
If you have a consumer on serverID=001 polling its own provider (serverID=001) then you have a misconfiguration.
We were doing a lot of writes during this time and there were cmp -1 104480 or simiar entries in the log. I had similar issue in the past while running 2.4.37 and it crashed slapd at that time but it didnt this time. The CSN were all synced at the end without any issue.
Could you advise what could be causing this?
It's comparing the consumer's cookie against records in the syncprov sessionlog, and ignoring sessionlog records that are older than the consumer's cookie. It's normal and harmless.
Oct 8 20:36:50 servername slapd[58097]: srs csn 20141008181030.452659Z#000000#001#000000
Oct 8 20:36:50 servername slapd[58097]: log csn 20140723214017.586869Z#000000#001#000000
Oct 8 20:36:50 servername slapd[58097]: cmp -1, too old
Oct 8 20:36:50 servername slapd[58097]: log csn 20140723214017.847644Z#000000#001#000000
Oct 8 20:36:50 servername slapd[58097]: cmp -1, too old
Oct 8 20:36:50 servername slapd[58097]: log csn 20140723214122.276227Z#000000#001#000000
Oct 8 20:36:50 servername slapd[58097]: cmp -1, too old
Oct 8 20:36:50 servername slapd[58097]: log csn 20140723214515.997173Z#000000#001#000000
Oct 8 20:36:50 servername slapd[58097]: cmp -1, too old
Oct 8 20:36:50 servername slapd[58097]: log csn 20140723214734.650752Z#000000#001#000000
Oct 8 20:36:50 servername slapd[58097]: log csn 20140723220152.569135Z#000000#003#000000
Oct 8 20:36:50 servername slapd[58097]: cmp -1, too old
Oct 8 20:36:50 servername slapd[58097]: log csn 20140723220328.184724Z#000000#001#000000
Oct 8 20:36:50 servername slapd[58097]: cmp -1, too old
Oct 8 20:36:50 servername slapd[58097]: log csn 20140723222016.864642Z#000000#001#000000
Oct 8 20:36:50 servername slapd[58097]: cmp -1, too old
Oct 8 20:36:50 servername slapd[58097]: log csn 20140723232832.307038Z#000000#003#000000
Oct 8 20:36:50 servername slapd[58097]: cmp -1, too old
Oct 8 20:36:50 servername slapd[58097]: log csn 20140723232958.001298Z#000000#003#000000
On 2014-10-08 6:24 PM, Howard Chu wrote:
Daniel Jung wrote:
Running on 2.4.39 centos 6.4 in MMR setup ( 4 servers ). 001 is the provider that was being written to at the time. The log is from 001. Could you advise whether my understanding of the log is correct?
synrepl consumer on serverID=001 is polling syncrepl provider on serverID=001 and 003 and gets the CSN that is older that its own.
If you have a consumer on serverID=001 polling its own provider (serverID=001) then you have a misconfiguration.
Based on the log below, thats what i surmised even though in the config, olcsynrepl on sid=001 use other than its own as the providers. When you say consumer, you are referring to a server(slave/master) that is using syncrepl to sync the data? Would it be possible to know show this consumder RID in the message below ? #001# is SID and NOT RID correct?
We were doing a lot of writes during this time and there were cmp -1 104480 or simiar entries in the log. I had similar issue in the past while running 2.4.37 and it crashed slapd at that time but it didnt this time. The CSN were all synced at the end without any issue.
Could you advise what could be causing this?
It's comparing the consumer's cookie against records in the syncprov sessionlog, and ignoring sessionlog records that are older than the consumer's cookie. It's normal and harmless.
Oct 8 20:36:50 servername slapd[58097]: srs csn 20141008181030.452659Z#000000#001#000000
Oct 8 20:36:50 servername slapd[58097]: log csn 20140723214017.586869Z#000000#001#000000
Oct 8 20:36:50 servername slapd[58097]: cmp -1, too old
Oct 8 20:36:50 servername slapd[58097]: log csn 20140723214017.847644Z#000000#001#000000
Oct 8 20:36:50 servername slapd[58097]: cmp -1, too old
Oct 8 20:36:50 servername slapd[58097]: log csn 20140723214122.276227Z#000000#001#000000
Oct 8 20:36:50 servername slapd[58097]: cmp -1, too old
Oct 8 20:36:50 servername slapd[58097]: log csn 20140723214515.997173Z#000000#001#000000
Oct 8 20:36:50 servername slapd[58097]: cmp -1, too old
Oct 8 20:36:50 servername slapd[58097]: log csn 20140723214734.650752Z#000000#001#000000
Oct 8 20:36:50 servername slapd[58097]: log csn 20140723220152.569135Z#000000#003#000000
Oct 8 20:36:50 servername slapd[58097]: cmp -1, too old
Oct 8 20:36:50 servername slapd[58097]: log csn 20140723220328.184724Z#000000#001#000000
Oct 8 20:36:50 servername slapd[58097]: cmp -1, too old
Oct 8 20:36:50 servername slapd[58097]: log csn 20140723222016.864642Z#000000#001#000000
Oct 8 20:36:50 servername slapd[58097]: cmp -1, too old
Oct 8 20:36:50 servername slapd[58097]: log csn 20140723232832.307038Z#000000#003#000000
Oct 8 20:36:50 servername slapd[58097]: cmp -1, too old
Oct 8 20:36:50 servername slapd[58097]: log csn 20140723232958.001298Z#000000#003#000000
Also, would reducing the SpSessionlog to smaller value, currently set at 100000 show less of this behaviour? There were 104480 such lines in the log in the matter of under few secs. I understand that sessionlog is stored in the memory and should be superfast, just wondering if this is something that needs to be tuned better.
Thanks
On 2014-10-08 6:24 PM, Howard Chu wrote:
Daniel Jung wrote:
Running on 2.4.39 centos 6.4 in MMR setup ( 4 servers ). 001 is the provider that was being written to at the time. The log is from 001. Could you advise whether my understanding of the log is correct?
synrepl consumer on serverID=001 is polling syncrepl provider on serverID=001 and 003 and gets the CSN that is older that its own.
If you have a consumer on serverID=001 polling its own provider (serverID=001) then you have a misconfiguration.
We were doing a lot of writes during this time and there were cmp -1 104480 or simiar entries in the log. I had similar issue in the past while running 2.4.37 and it crashed slapd at that time but it didnt this time. The CSN were all synced at the end without any issue.
Could you advise what could be causing this?
It's comparing the consumer's cookie against records in the syncprov sessionlog, and ignoring sessionlog records that are older than the consumer's cookie. It's normal and harmless.
Oct 8 20:36:50 servername slapd[58097]: srs csn 20141008181030.452659Z#000000#001#000000
Oct 8 20:36:50 servername slapd[58097]: log csn 20140723214017.586869Z#000000#001#000000
Oct 8 20:36:50 servername slapd[58097]: cmp -1, too old
Oct 8 20:36:50 servername slapd[58097]: log csn 20140723214017.847644Z#000000#001#000000
Oct 8 20:36:50 servername slapd[58097]: cmp -1, too old
Oct 8 20:36:50 servername slapd[58097]: log csn 20140723214122.276227Z#000000#001#000000
Oct 8 20:36:50 servername slapd[58097]: cmp -1, too old
Oct 8 20:36:50 servername slapd[58097]: log csn 20140723214515.997173Z#000000#001#000000
Oct 8 20:36:50 servername slapd[58097]: cmp -1, too old
Oct 8 20:36:50 servername slapd[58097]: log csn 20140723214734.650752Z#000000#001#000000
Oct 8 20:36:50 servername slapd[58097]: log csn 20140723220152.569135Z#000000#003#000000
Oct 8 20:36:50 servername slapd[58097]: cmp -1, too old
Oct 8 20:36:50 servername slapd[58097]: log csn 20140723220328.184724Z#000000#001#000000
Oct 8 20:36:50 servername slapd[58097]: cmp -1, too old
Oct 8 20:36:50 servername slapd[58097]: log csn 20140723222016.864642Z#000000#001#000000
Oct 8 20:36:50 servername slapd[58097]: cmp -1, too old
Oct 8 20:36:50 servername slapd[58097]: log csn 20140723232832.307038Z#000000#003#000000
Oct 8 20:36:50 servername slapd[58097]: cmp -1, too old
Oct 8 20:36:50 servername slapd[58097]: log csn 20140723232958.001298Z#000000#003#000000
openldap-technical@openldap.org
-
Daniel Jung -
Howard Chu