Context
Aerospike Cross DataCenter Replication (XDR) is one of the most powerful features of Aerospike Enterprise Edition. It allows geographically separate datacenters to replicate records giving near real time access to data on a global basis. XDR already logs aggregate information into log files in a configurable manner, however, at times it might be necessary to see exactly what is happening on a record by record basis. To do this the facility to trace the progress of records through the various sub-systems that make up XDR exists. This is XDR tracing. XDR tracing can be used as of version 3.10 for debugging purposes or to provide useful tuning information. The way in which tracing is enabled is dependant on the Aerospike version and differs between version 5.0 and later and earlier versions.Method
Aerospike 5.0 and later
Switching on tracing comprises two parts. The first part is to switch on
The second part of the command defines the sampling rate (that is, one out of this many records will be traced; set to 1 to see every record, but this may spam the logs on a busy cluster):
The tracing messages in the log will be of the following form:
detail level logging for the XDR module:
Admin> asinfo -v "log-set:id=0;xdr=detail" 172.17.0.3:3000 (172.17.0.3) returned: ok 2a3b8ae3df9f:3000 (172.17.0.4) returned: ok
The second part of the command defines the sampling rate (that is, one out of this many records will be traced; set to 1 to see every record, but this may spam the logs on a busy cluster):
Admin> asinfo -v 'set-config:context=xdr;trace-sample=100000' 172.17.0.3:3000 (172.17.0.3) returned: ok 2a3b8ae3df9f:3000 (172.17.0.4) returned: ok Admin>
The tracing messages in the log will be of the following form:
root@2a3b8ae3df9f:/# tail -f /var/log/aerospike.log | grep -i trace
Nov 23 2020 13:41:45 GMT: DETAIL (xdr): (xdr_ee.c:122) trace 210b7900:343834905300_201123_134145.300:0090:390084:xdr5-dest complete 0
Nov 23 2020 13:42:47 GMT: DETAIL (xdr): (xdr_ee.c:122) trace 5be479a0:343834967338_201123_134247.338:0156:452029:* transaction - {test|testset} pid 2992
Nov 23 2020 13:42:47 GMT: DETAIL (xdr): (xdr_ee.c:122) trace 5be479a0:343834967338_201123_134247.338:0156:452029:xdr5-dest submit
Nov 23 2020 13:42:51 GMT: DETAIL (xdr): (xdr_ee.c:122) trace 5be479a0:343834967338_201123_134247.338:0183:456481:xdr5-dest trim
Nov 23 2020 13:42:56 GMT: DETAIL (xdr): (xdr_ee.c:122) trace 1dceeba0:343834976351_201123_134256.351:0165:461041:* transaction - {test|testset} pid 887
Nov 23 2020 13:42:56 GMT: DETAIL (xdr): (xdr_ee.c:122) trace 1dceeba0:343834976351_201123_134256.351:0165:461041:xdr5-dest submit
Nov 23 2020 13:43:00 GMT: DETAIL (xdr): (xdr_ee.c:122) trace 1dceeba0:343834976351_201123_134256.351:0183:465423:xdr5-dest trim
Nov 23 2020 13:49:33 GMT: DETAIL (xdr): (xdr_ee.c:122) trace 7a709ac0:343835373007_201123_134933.007:0167:857689:* transaction - {test|testset} pid 2658
Nov 23 2020 13:49:33 GMT: DETAIL (xdr): (xdr_ee.c:122) trace 7a709ac0:343835373007_201123_134933.007:0167:857689:xdr5-dest submit
Nov 23 2020 13:49:36 GMT: DETAIL (xdr): (xdr_ee.c:122) trace 7a709ac0:343835373007_201123_134933.007:0183:861169:xdr5-dest trim
Nov 23 2020 13:52:24 GMT: DETAIL (xdr): (xdr_ee.c:122) trace 857901a0:343835544420_201123_135224.420:0162:029099:* transaction - {test|testset} pid 3000
Nov 23 2020 13:52:24 GMT: DETAIL (xdr): (xdr_ee.c:122) trace 857901a0:343835544420_201123_135224.420:0162:029101:xdr5-dest submit
Nov 23 2020 13:52:28 GMT: DETAIL (xdr): (xdr_ee.c:122) trace 857901a0:343835544420_201123_135224.420:0183:032842:xdr5-dest trim
Nov 23 2020 13:53:02 GMT: DETAIL (xdr): (xdr_ee.c:122) trace 2ec89fa0:343835582533_201123_135302.533:0090:067211:* transaction - {test|testset} pid 1521
Nov 23 2020 13:53:02 GMT: DETAIL (xdr): (xdr_ee.c:122) trace 2ec89fa0:343835582533_201123_135302.533:0090:067211:xdr5-dest submit
Nov 23 2020 13:53:02 GMT: DETAIL (xdr): (xdr_ee.c:122) trace 2ec89fa0:343835582533_201123_135302.533:0183:067289:xdr5-dest process
Nov 23 2020 13:53:02 GMT: DETAIL (xdr): (xdr_ee.c:122) trace 2ec89fa0:343835582533_201123_135302.533:0093:067289:xdr5-dest read
Nov 23 2020 13:53:02 GMT: DETAIL (xdr): (xdr_ee.c:122) trace 2ec89fa0:343835582533_201123_135302.533:0093:067289:xdr5-dest ship (read lut 343835582533_201123_135302.5
Output should be sent to Aerospike Support for analysis.
After completing any investigation the change the log level for XDR should be switched back to the default level of info:
Admin> asinfo -v "log-set:id=0;xdr=info" 172.17.0.3:3000 (172.17.0.3) returned: ok 2a3b8ae3df9f:3000 (172.17.0.4) returned: ok