How to trigger re-replication for unreplicated records within a strongly consistent Aerospike namespace

The Aerospike Knowledge Base has moved to https://support.aerospike.com. Content on https://discuss.aerospike.com is being migrated to either https://support.aerospike.com or https://docs.aerospike.com. Maintenance on articles stored in this repository ceased on December 31st 2022 and this article may be stale. If you have any questions, please do not hesitate to raise a case via https://support.aerospike.com.

How to trigger re-replication for unreplicated records within a strongly consistent Aerospike namespace

Context

When an Aerospike namespace is running in Strong Consistency mode, it ensures that all transactions acknowledged as successful to the client are replicated between all copies of a record. Sometimes a transaction may fail in-flight, perhaps due to a timeout or other temporal factor. In these instances a record may not be replicated across all copies. To ensure that reads are consistent, when a record is read, the replication status is checked. If the record is not shown as replicated then a write (called a re-replication) is initiated within the cluster to replicate the record to the other copies and ensure consistency. For expediency, the replication status of the record is kept in memory. If it were held on disk in addition to storing it in the primary index, the record could not be written to disk until all replicas writes had been acknowledged, which would be unacceptably slow. This means that when nodes cold start the replication status of the record is lost. The net effect of this is that there can be a temporary increase in read latency as each read transaction has to wait for a write transaction to re-replicate the record. In certain circumstances it may be desirable to pro-actively trigger re-replication across the cluster to remove any read latency penalty. The purpose of this article is to examine 4 methods of re-replication of records across an entire cluster and discuss their relative merits.

Test Description

The test used a 5 node cluster where the bar namespace was configured for strong consistency. The basic state of the cluster is as follows:

Admin> info
~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~Network Information (2021-05-17 17:48:03 UTC)~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~
             Node|         Node ID|             IP|    Build|Migrations|~~~~~~~~~~~~~~~~~Cluster~~~~~~~~~~~~~~~~~|Client|  Uptime
                 |                |               |         |          |Size|       Key|Integrity|      Principal| Conns|        
172.17.0.3:3000  | BB9030011AC4202|172.17.0.3:3000|E-5.5.0.9|   0.000  |   5|3F45B307A5|True     |BB9070011AC4202|     1|00:54:04
172.17.0.4:3000  | BB9040011AC4202|172.17.0.4:3000|E-5.5.0.9|   0.000  |   5|3F45B307A5|True     |BB9070011AC4202|     2|00:54:04
172.17.0.5:3000  | BB9050011AC4202|172.17.0.5:3000|E-5.5.0.9|   0.000  |   5|3F45B307A5|True     |BB9070011AC4202|     1|00:54:04
172.17.0.6:3000  | BB9060011AC4202|172.17.0.6:3000|E-5.5.0.9|   0.000  |   5|3F45B307A5|True     |BB9070011AC4202|     1|00:54:03
66ab02eef3aa:3000|*BB9070011AC4202|172.17.0.7:3000|E-5.5.0.9|   0.000  |   5|3F45B307A5|True     |BB9070011AC4202|     2|00:54:03
Number of rows: 5

~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~Namespace Usage Information (2021-05-17 17:48:03 UTC)~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~
Namespace|             Node|   Total|Expirations|Evictions|  Stop|~~~~~~~~~~~~Disk~~~~~~~~~~~~|~~~~~~~~~~~Memory~~~~~~~~~~|~Primary~
         |                 | Records|           |         |Writes|      Used|Used%|HWM%|Avail%|      Used|Used%|HWM%|Stop%|~~Index~~
         |                 |        |           |         |      |          |     |    |      |          |     |    |     |     Type
bar      |172.17.0.3:3000  | 3.998 M|    0.000  |  0.000  |False |244.023 MB|   24|   0|    75|244.023 MB|    6|   0|   90|shmem    
bar      |172.17.0.4:3000  | 4.002 M|    0.000  |  0.000  |False |244.271 MB|   24|   0|    75|244.271 MB|    6|   0|   90|shmem    
bar      |172.17.0.5:3000  | 4.000 M|    0.000  |  0.000  |False |244.161 MB|   24|   0|    75|244.161 MB|    6|   0|   90|shmem    
bar      |172.17.0.6:3000  | 3.999 M|    0.000  |  0.000  |False |244.107 MB|   24|   0|    75|244.107 MB|    6|   0|   90|shmem    
bar      |66ab02eef3aa:3000| 4.000 M|    0.000  |  0.000  |False |244.140 MB|   24|   0|    75|244.140 MB|    6|   0|   90|shmem    
bar      |                 |20.000 M|    0.000  |  0.000  |      |  1.192 GB|     |    |      |  1.192 GB|     |    |     |         
test     |172.17.0.3:3000  | 0.000  |    0.000  |  0.000  |False |        --|   --|   0|    --|  0.000 B |    0|   0|   90|shmem    
test     |172.17.0.4:3000  | 0.000  |    0.000  |  0.000  |False |        --|   --|   0|    --|  0.000 B |    0|   0|   90|shmem    
test     |172.17.0.5:3000  | 0.000  |    0.000  |  0.000  |False |        --|   --|   0|    --|  0.000 B |    0|   0|   90|shmem    
test     |172.17.0.6:3000  | 0.000  |    0.000  |  0.000  |False |        --|   --|   0|    --|  0.000 B |    0|   0|   90|shmem    
test     |66ab02eef3aa:3000| 0.000  |    0.000  |  0.000  |False |        --|   --|   0|    --|  0.000 B |    0|   0|   90|shmem    
test     |                 | 0.000  |    0.000  |  0.000  |      |        --|     |    |      |  0.000 B |     |    |     |         
Number of rows: 10

To force the records into an unreplicated state, the nodes of the cluster were shutdown cleanly and then cold started. A dirty shutdown is not necessary, simply cold starting will remove the replication information from the index entry as the index is rebuilt from disk. As expected the nodes come up fully available but all records will be in an unreplicated state. After this, the 4 methods of re-replication were executed resetting after each test. The following ticker line shows the re-replication happening:

{ns_name} re-repl: all-triggers (525,0,32)

Note: in version 5.7, the number of unreplicated records will also be shown on this line as a statistic to track the number of unreplicated records will be added:

{ns_name} re-repl: all-triggers (261934,0,0) unreplicated-records 3507484

There is a also a histogram showing the latency of re-replication transactions:

{ns}-re-repl

Method 1 - Scan and Touch UDF

The first method checked was a tried and trusted technique known as a scan and touch UDF. Here, all records in the namespace are scanned and a simple operation, known as a touch is executed. This is enough to cause an unreplicated record to re-replicate. The TTL is set to -2 as otherwise the TTL will be updated with the default TTL for the namespace (if TTL is leveraged, otherwise, this is not necessary).

root@66ab02eef3aa:~# cat re_repl.lua 
function touch(rec)
   record.set_ttl(rec, -2)
   aerospike:update(rec)
end

root@66ab02eef3aa:~# aql
Seed:         127.0.0.1
User:         None
Config File:  /etc/aerospike/astools.conf /root/.aerospike/astools.conf 
Aerospike Query Client
Version 5.0.1
C Client Version 4.6.17
Copyright 2012-2020 Aerospike. All rights reserved.
aql> register module 're_repl.lua'
OK, 1 module added.
aql> show modules
+---------------+--------------------------------------------+-------+
| filename      | hash                                       | type  |
+---------------+--------------------------------------------+-------+
| "re_repl.lua" | "44d424f78bfaf33e99f442bb172b18f08b0468c2" | "LUA" |
+---------------+--------------------------------------------+-------+
[127.0.0.1:3000] 1 row in set (0.001 secs)

+---------------+--------------------------------------------+-------+
| filename      | hash                                       | type  |
+---------------+--------------------------------------------+-------+
| "re_repl.lua" | "44d424f78bfaf33e99f442bb172b18f08b0468c2" | "LUA" |
+---------------+--------------------------------------------+-------+
[172.17.0.6:3000] 1 row in set (0.002 secs)

+---------------+--------------------------------------------+-------+
| filename      | hash                                       | type  |
+---------------+--------------------------------------------+-------+
| "re_repl.lua" | "44d424f78bfaf33e99f442bb172b18f08b0468c2" | "LUA" |
+---------------+--------------------------------------------+-------+
[172.17.0.3:3000] 1 row in set (0.003 secs)

+---------------+--------------------------------------------+-------+
| filename      | hash                                       | type  |
+---------------+--------------------------------------------+-------+
| "re_repl.lua" | "44d424f78bfaf33e99f442bb172b18f08b0468c2" | "LUA" |
+---------------+--------------------------------------------+-------+
[172.17.0.4:3000] 1 row in set (0.004 secs)

+---------------+--------------------------------------------+-------+
| filename      | hash                                       | type  |
+---------------+--------------------------------------------+-------+
| "re_repl.lua" | "44d424f78bfaf33e99f442bb172b18f08b0468c2" | "LUA" |
+---------------+--------------------------------------------+-------+
[172.17.0.5:3000] 1 row in set (0.005 secs)

OK

aql> execute re_repl.touch() on bar
OK, Scan job (6092651845346587156) created.

aql> 

The scan can be seen starting in the logs. Note that an older client was used leveraging the depreacted priority rather than specifying an RPS and so 5000 is used. The data shows later that the ops/sec is lower than 5000.

May 20 2021 15:12:32 GMT: INFO (scan): (scan.c:457) low-priority scan from old client will use 5000 rps

As expected, the log line shows re-replication happening.

May 20 2021 15:12:38 GMT: INFO (info): (ticker.c:967) {bar} re-repl: all-triggers (19700,0,0)

The histogram gives a much more granular picture. As the start time is known from the log line it is possible to be very focused when checking the results in asadm:

Results - UDF Scan and Touch

Log-analyzer> histogram -h re-repl -f 'May 20 2021 15:12:00'  -p 1000 -d 800
~~~~~~~~~~~~~~~~~~~~~~~~re-repl Latency (Page-1)~~~~~~~~~~~~~~~~~~~~~~~~
NODE                :   bb9070011ac4202   .        .         .         |   
.                   :   % >1ms            % >8ms   % >64ms   ops/sec   |   
May 20 2021 15:12:50:   99.96             91.74    10.56     2582.5    |   
May 20 2021 15:13:00:   100.00            94.89    17.88     2112.9    |   
May 20 2021 15:13:10:   100.00            96.31    20.72     1901.5    |   
May 20 2021 15:13:20:   99.99             96.32    23.98     1793.0    |   
May 20 2021 15:13:30:   99.99             95.16    19.18     2070.4    |   
May 20 2021 15:13:40:   100.00            96.82    25.00     1851.8    |   
May 20 2021 15:13:50:   99.98             96.16    17.45     2171.9    |   
May 20 2021 15:14:00:   100.00            95.26    18.45     2120.5    |   
May 20 2021 15:14:10:   99.98             94.77    17.47     2153.0    |   
May 20 2021 15:14:20:   99.98             95.10    16.55     2180.3    |   
May 20 2021 15:14:30:   99.99             91.87    8.84      2785.6    |   
May 20 2021 15:14:40:   100.00            94.64    13.35     2292.2    |   
May 20 2021 15:14:50:   99.98             92.98    17.28     2340.3    |   
May 20 2021 15:15:00:   99.97             92.59    13.48     2191.8    |   
May 20 2021 15:15:10:   99.98             93.25    9.91      2631.5    |   
May 20 2021 15:15:20:   99.96             92.22    8.60      2729.0    |   
May 20 2021 15:15:30:   99.99             94.08    11.30     2520.7    |   
May 20 2021 15:15:40:   99.96             92.52    10.14     2610.4    |   
May 20 2021 15:15:50:   99.98             92.56    11.82     2462.5    |   
May 20 2021 15:16:00:   99.97             93.97    15.24     2272.0    |   
May 20 2021 15:16:10:   99.98             92.00    9.54      2679.4    |   
May 20 2021 15:16:20:   99.97             92.70    10.59     2583.4    |   
May 20 2021 15:16:30:   99.99             94.90    22.54     1749.6    |   
May 20 2021 15:16:40:   99.97             93.35    12.76     2430.1    |   
May 20 2021 15:16:50:   99.99             95.93    18.24     2097.0    |   
May 20 2021 15:17:00:   99.97             92.49    13.07     2424.2    |   
May 20 2021 15:17:10:   99.98             93.46    17.41     2061.8    |   
May 20 2021 15:17:20:   99.98             92.39    7.87      2797.8    |   
May 20 2021 15:17:30:   99.98             94.32    11.15     2621.8    |   
May 20 2021 15:17:40:   99.98             91.45    7.98      2805.4    |   
May 20 2021 15:17:50:   99.93             90.57    6.59      3003.8    |   
May 20 2021 15:18:00:   99.94             90.21    7.48      2888.8    |   
May 20 2021 15:18:10:   99.93             90.61    6.87      2979.6    |   
May 20 2021 15:18:20:   99.98             92.12    6.62      2957.0    |   
May 20 2021 15:18:30:   99.95             90.09    8.32      2806.0    |   
May 20 2021 15:18:40:   99.97             91.23    8.93      2782.7    |   
May 20 2021 15:18:50:   99.98             91.88    7.32      2862.1    |   
May 20 2021 15:19:00:   99.97             93.00    9.58      2665.9    |   
May 20 2021 15:19:10:   99.95             90.53    7.72      2645.0    |   
May 20 2021 15:19:20:   99.98             92.51    7.79      2835.2    |   
May 20 2021 15:19:30:   99.95             90.07    6.71      2989.1    |   
May 20 2021 15:19:40:   99.95             90.94    7.33      2940.8    |   
May 20 2021 15:19:50:   99.97             91.36    8.13      2887.1    |   
May 20 2021 15:20:00:   99.95             91.91    7.66      2877.9    |   
May 20 2021 15:20:10:   99.96             90.09    7.96      2898.7    |   
May 20 2021 15:20:20:   99.94             90.95    8.52      2852.3    |   
May 20 2021 15:20:30:   99.92             89.09    7.12      2978.5    |   
May 20 2021 15:20:40:   99.93             89.10    6.18      3066.3    |   
May 20 2021 15:20:50:   99.97             91.11    7.24      2895.3    |   
May 20 2021 15:21:00:   99.98             93.13    10.95     2537.0    |   
May 20 2021 15:21:10:   99.94             89.96    6.82      2954.0    |   
May 20 2021 15:21:20:   99.95             91.00    6.84      2976.0    |   
May 20 2021 15:21:30:   99.94             90.66    6.25      3019.4    |   
May 20 2021 15:21:40:   99.97             92.55    8.79      2751.8    |   
May 20 2021 15:21:50:   99.95             90.78    6.95      2954.8    |   
May 20 2021 15:22:00:   99.97             91.54    8.76      2731.8    |   
May 20 2021 15:22:10:   99.98             91.24    7.55      2837.3    |   
May 20 2021 15:22:20:   99.95             91.67    7.35      2908.3    |   
May 20 2021 15:22:30:   99.96             92.10    7.69      2812.4    |   
May 20 2021 15:22:40:   99.97             90.94    9.12      2791.0    |   
May 20 2021 15:22:50:   99.96             90.02    6.95      2687.5    |   
May 20 2021 15:23:00:   99.95             88.84    6.35      3062.9    |   
May 20 2021 15:23:10:   99.96             92.23    7.55      2851.9    |   
May 20 2021 15:23:20:   99.97             89.78    6.58      3034.7    |   
May 20 2021 15:23:30:   99.95             90.51    6.88      2985.9    |   
May 20 2021 15:23:40:   99.96             91.51    8.01      2828.0    |   
May 20 2021 15:23:50:   99.97             92.55    8.30      2809.1    |   
May 20 2021 15:24:00:   99.92             88.98    6.21      3055.4    |   
May 20 2021 15:24:10:   99.95             90.98    7.86      2928.3    |   
May 20 2021 15:24:20:   99.95             91.04    7.97      2855.3    |   
May 20 2021 15:24:30:   99.95             89.22    6.48      3133.4    |   
May 20 2021 15:24:40:   99.97             91.78    9.92      2774.9    |   
May 20 2021 15:24:50:   99.96             91.05    5.52      3041.0    |   
May 20 2021 15:25:00:   99.96             90.88    6.84      2913.3    |   
May 20 2021 15:25:10:   94.56             49.70    4.28      1181.0    |   
avg                 :   99.00             91.00    10.00     2642.0    |   
max                 :   100.00            96.82    25.00     3133.4    |   

Log-analyzer> 

Method 2 - UDF Peek

The second UDF is even more simple and does not require even touching the record. This UDF simply peeks at the record, which is enough to trigger re-replication.

root@66ab02eef3aa:~# cat re_repl2.lua 
function doNothing(r)
return
end

root@66ab02eef3aa:~# aql
Seed:         127.0.0.1
User:         None
Config File:  /etc/aerospike/astools.conf /root/.aerospike/astools.conf 
Aerospike Query Client
Version 5.0.1
C Client Version 4.6.17
Copyright 2012-2020 Aerospike. All rights reserved.
aql> register module 're_repl2.lua'
OK, 1 module added.

aql> show modules
+----------------+--------------------------------------------+-------+
| filename       | hash                                       | type  |
+----------------+--------------------------------------------+-------+
| "re_repl.lua"  | "44d424f78bfaf33e99f442bb172b18f08b0468c2" | "LUA" |
| "re_repl2.lua" | "e2c38328ce8512302b6ac23ece55ce06a0462411" | "LUA" |
+----------------+--------------------------------------------+-------+
[127.0.0.1:3000] 2 rows in set (0.001 secs)

+----------------+--------------------------------------------+-------+
| filename       | hash                                       | type  |
+----------------+--------------------------------------------+-------+
| "re_repl.lua"  | "44d424f78bfaf33e99f442bb172b18f08b0468c2" | "LUA" |
| "re_repl2.lua" | "e2c38328ce8512302b6ac23ece55ce06a0462411" | "LUA" |
+----------------+--------------------------------------------+-------+
[172.17.0.6:3000] 2 rows in set (0.002 secs)

+----------------+--------------------------------------------+-------+
| filename       | hash                                       | type  |
+----------------+--------------------------------------------+-------+
| "re_repl.lua"  | "44d424f78bfaf33e99f442bb172b18f08b0468c2" | "LUA" |
| "re_repl2.lua" | "e2c38328ce8512302b6ac23ece55ce06a0462411" | "LUA" |
+----------------+--------------------------------------------+-------+
[172.17.0.3:3000] 2 rows in set (0.004 secs)

+----------------+--------------------------------------------+-------+
| filename       | hash                                       | type  |
+----------------+--------------------------------------------+-------+
| "re_repl.lua"  | "44d424f78bfaf33e99f442bb172b18f08b0468c2" | "LUA" |
| "re_repl2.lua" | "e2c38328ce8512302b6ac23ece55ce06a0462411" | "LUA" |
+----------------+--------------------------------------------+-------+
[172.17.0.4:3000] 2 rows in set (0.005 secs)

+----------------+--------------------------------------------+-------+
| filename       | hash                                       | type  |
+----------------+--------------------------------------------+-------+
| "re_repl.lua"  | "44d424f78bfaf33e99f442bb172b18f08b0468c2" | "LUA" |
| "re_repl2.lua" | "e2c38328ce8512302b6ac23ece55ce06a0462411" | "LUA" |
+----------------+--------------------------------------------+-------+
[172.17.0.5:3000] 2 rows in set (0.006 secs)

OK

aql> execute re_repl2.doNothing() on bar
OK, Scan job (6173968442599032398) created.

The re-replication is tracked by tailing the aerospike.log and when it is finished the re-replication histogram is used to get the relevant details.

Results - UDF Peek

Log-analyzer> histogram -h re-repl -f 'May 20 2021 14:40:00'  -p 1000 -d 710
~~~~~~~~~~~~~~~~~~~~~~~~re-repl Latency (Page-1)~~~~~~~~~~~~~~~~~~~~~~~~
NODE                :   bb9070011ac4202   .        .         .         |   
.                   :   % >1ms            % >8ms   % >64ms   ops/sec   |   
May 20 2021 14:42:30:   99.86             86.91    3.96      4459.0    |   
May 20 2021 14:42:40:   99.91             90.42    8.44      3774.2    |   
May 20 2021 14:42:50:   99.89             89.00    7.85      3798.7    |   
May 20 2021 14:43:00:   99.93             90.99    8.71      3685.0    |   
May 20 2021 14:43:10:   99.92             91.79    9.83      3713.2    |   
May 20 2021 14:43:20:   99.96             91.30    10.70     3510.1    |   
May 20 2021 14:43:30:   99.94             91.05    8.08      3860.5    |   
May 20 2021 14:43:40:   99.95             91.98    11.12     3447.5    |   
May 20 2021 14:43:50:   99.98             94.30    15.82     3151.4    |   
May 20 2021 14:44:00:   99.97             93.24    14.16     3305.9    |   
May 20 2021 14:44:10:   99.96             93.74    17.83     2758.9    |   
May 20 2021 14:44:20:   99.97             94.25    15.83     3231.2    |   
May 20 2021 14:44:30:   99.91             92.49    11.46     3413.4    |   
May 20 2021 14:44:40:   99.95             92.19    10.63     3661.0    |   
May 20 2021 14:44:50:   99.96             91.44    7.74      3683.9    |   
May 20 2021 14:45:00:   99.93             91.13    7.09      3935.3    |   
May 20 2021 14:45:10:   99.96             91.45    8.04      3742.0    |   
May 20 2021 14:45:20:   99.95             90.88    6.15      4086.2    |   
May 20 2021 14:45:30:   99.95             90.92    8.64      3657.9    |   
May 20 2021 14:45:40:   99.90             92.05    9.15      3662.9    |   
May 20 2021 14:45:50:   99.95             92.17    11.56     3296.0    |   
May 20 2021 14:46:00:   99.96             91.71    7.51      3507.3    |   
May 20 2021 14:46:10:   99.93             91.52    8.75      3809.0    |   
May 20 2021 14:46:20:   99.94             91.86    8.86      3743.4    |   
May 20 2021 14:46:30:   99.94             91.34    8.08      3835.8    |   
May 20 2021 14:46:40:   99.95             91.71    9.93      3590.9    |   
May 20 2021 14:46:50:   99.96             92.49    10.65     3512.0    |   
May 20 2021 14:47:00:   99.94             91.82    9.26      3701.5    |   
May 20 2021 14:47:10:   99.96             92.21    7.89      3686.5    |   
May 20 2021 14:47:20:   99.92             91.91    9.11      3723.9    |   
May 20 2021 14:47:30:   99.94             90.67    6.72      3867.7    |   
May 20 2021 14:47:40:   99.93             91.56    8.82      3671.7    |   
May 20 2021 14:47:50:   99.97             91.92    9.12      3677.7    |   
May 20 2021 14:48:00:   99.94             91.78    8.27      3860.8    |   
May 20 2021 14:48:10:   99.93             91.97    10.39     3441.4    |   
May 20 2021 14:48:20:   99.94             92.04    8.45      3697.8    |   
May 20 2021 14:48:30:   99.94             91.27    7.44      3851.8    |   
May 20 2021 14:48:40:   99.94             90.67    9.43      3595.3    |   
May 20 2021 14:48:50:   99.94             91.69    7.37      3912.2    |   
May 20 2021 14:49:00:   99.98             92.41    8.73      3696.2    |   
May 20 2021 14:49:10:   99.95             91.09    8.74      3804.6    |   
May 20 2021 14:49:20:   99.93             92.50    10.43     3580.3    |   
May 20 2021 14:49:30:   99.98             92.89    10.31     3657.8    |   
May 20 2021 14:49:40:   99.94             91.44    8.67      3754.5    |   
May 20 2021 14:49:50:   99.95             91.13    7.67      3743.7    |   
May 20 2021 14:50:00:   99.94             92.15    9.76      3625.4    |   
May 20 2021 14:50:10:   99.95             90.93    9.91      3489.8    |   
May 20 2021 14:50:20:   99.92             90.92    7.98      3334.5    |   
May 20 2021 14:50:30:   99.96             91.78    12.11     3192.8    |   
May 20 2021 14:50:40:   99.94             92.09    8.58      3798.0    |   
May 20 2021 14:50:50:   99.97             94.59    21.72     2628.2    |   
May 20 2021 14:51:00:   99.99             95.35    22.02     2741.9    |   
May 20 2021 14:51:10:   99.99             95.45    23.78     2752.0    |   
May 20 2021 14:51:20:   99.97             93.34    13.90     3240.9    |   
May 20 2021 14:51:30:   99.91             89.14    6.85      3624.7    |   
May 20 2021 14:51:40:   94.63             66.74    3.24      1331.0    |   
avg                 :   99.00             91.00    10.00     3544.0    |   
max                 :   99.99             95.45    23.78     4459.0    |   

Log-analyzer> 

Methods 3 and 4 - Client code solutions

The next two tests were conducted using client-based re-replication. Two methods of re-replicating using background operations were tested. The basic code used by both client methods is shown below. Each of the two cases was executed separately. For ease of testing in this experiment a Jupyter notebook was used to execute the code. The signficant part of the code is shown below.

import com.aerospike.client.AerospikeClient;
import com.aerospike.client.policy.WritePolicy;
import com.aerospike.client.Bin;
import com.aerospike.client.Key;
import com.aerospike.client.query.Statement;
import com.aerospike.client.Operation;
import com.aerospike.client.task.ExecuteTask;

int POLL_INTERVAL_MS = 3000;
int WAIT_TILL_COMPLETE_MS = 100000;

enum ExecOption{STMT, EXEC_ARG, UDF};

WritePolicy wpolicy = new WritePolicy();
wpolicy.sendKey = true;
wpolicy.maxRetries = 0;
// specify TTL here
wpolicy.expiration = -2;

void scanAndUpdate(String seedNodeIp, String namespace, Operation[] ops, ExecOption option) {
    System.out.format("Performing scan-and-update on namespace %s with option %s.\n", namespace, option);
    AerospikeClient client = new AerospikeClient(seedNodeIp, 3000);
    Statement stmt = new Statement();
    ExecuteTask task;
    stmt.setNamespace(namespace);
    switch(option) {
        case STMT:
            stmt.setOperations(ops);
            task = client.execute(wpolicy, stmt); 
            task.waitTillComplete(POLL_INTERVAL_MS, WAIT_TILL_COMPLETE_MS);
            break;
      case EXEC_ARG:
            task = client.execute(wpolicy, stmt, ops); 
            task.waitTillComplete(POLL_INTERVAL_MS, WAIT_TILL_COMPLETE_MS);
            break;
      default:
            System.out.format("Error: wrong ExecOption\n");
    }
    client.close();
    System.out.format("Scan-and-update done.\n");;
}

Results - Client method STMT

Log-analyzer> histogram -h re-repl -f 'May 20 2021 14:12:10'  -d 990 -p 1000
~~~~~~~~~~~~~~~~~~~~~~~~re-repl Latency (Page-1)~~~~~~~~~~~~~~~~~~~~~~~~
NODE                :   bb9070011ac4202   .        .         .         |   
.                   :   % >1ms            % >8ms   % >64ms   ops/sec   |   
May 20 2021 14:12:30:   99.97             94.54    14.26     2345.4    |   
May 20 2021 14:12:40:   99.96             94.01    12.77     2467.1    |   
May 20 2021 14:12:50:   99.98             93.50    13.02     2170.8    |   
May 20 2021 14:13:00:   99.98             92.47    9.30      2723.3    |   
May 20 2021 14:13:10:   99.95             94.17    13.74     2384.2    |   
May 20 2021 14:13:20:   99.98             94.29    13.49     2374.7    |   
May 20 2021 14:13:30:   99.98             92.76    11.27     2542.7    |   
May 20 2021 14:13:40:   99.97             94.54    14.79     2298.4    |   
May 20 2021 14:13:50:   100.00            97.81    23.56     1877.8    |   
May 20 2021 14:14:00:   99.99             95.25    20.90     1987.7    |   
May 20 2021 14:14:10:   100.00            96.65    19.62     2031.5    |   
May 20 2021 14:14:20:   99.98             94.58    23.65     1932.6    |   
May 20 2021 14:14:30:   100.00            95.86    20.44     2033.9    |   
May 20 2021 14:14:40:   99.97             94.62    13.69     2324.3    |   
May 20 2021 14:14:50:   99.99             96.44    17.27     2116.9    |   
May 20 2021 14:15:00:   99.99             95.36    15.25     2267.5    |   
May 20 2021 14:15:10:   99.99             96.37    19.52     2038.2    |   
May 20 2021 14:15:20:   100.00            96.13    21.07     1967.9    |   
May 20 2021 14:15:30:   100.00            95.21    16.26     2269.5    |   
May 20 2021 14:15:40:   99.99             96.65    21.87     1949.5    |   
May 20 2021 14:15:50:   100.00            95.82    19.04     2080.1    |   
May 20 2021 14:16:00:   99.98             94.62    16.78     2243.6    |   
May 20 2021 14:16:10:   99.98             95.53    16.88     2215.3    |   
May 20 2021 14:16:20:   100.00            95.74    17.97     1992.5    |   
May 20 2021 14:16:30:   100.00            96.34    20.18     2016.2    |   
May 20 2021 14:16:40:   99.99             96.18    22.74     1974.7    |   
May 20 2021 14:16:50:   100.00            95.02    17.86     2096.0    |   
May 20 2021 14:17:00:   100.00            95.71    18.87     2082.1    |   
May 20 2021 14:17:10:   100.00            96.45    18.69     2047.5    |   
May 20 2021 14:17:20:   100.00            95.82    19.09     2081.6    |   
May 20 2021 14:17:30:   100.00            97.91    26.19     1838.8    |   
May 20 2021 14:17:40:   100.00            95.88    17.60     2162.8    |   
May 20 2021 14:17:50:   100.00            95.69    18.95     2082.0    |   
May 20 2021 14:18:00:   100.00            95.01    16.40     2219.5    |   
May 20 2021 14:18:10:   100.00            95.64    19.83     2071.6    |   
May 20 2021 14:18:20:   100.00            96.00    21.54     1976.0    |   
May 20 2021 14:18:30:   99.99             95.69    19.39     2075.4    |   
May 20 2021 14:18:40:   99.99             97.33    24.82     1820.0    |   
May 20 2021 14:18:50:   100.00            97.05    23.99     1856.9    |   
May 20 2021 14:19:00:   100.00            96.27    25.82     1821.9    |   
May 20 2021 14:19:10:   100.00            97.09    31.00     1627.0    |   
May 20 2021 14:19:20:   100.00            97.45    25.70     1844.3    |   
May 20 2021 14:19:30:   99.99             96.80    26.93     1764.4    |   
May 20 2021 14:19:40:   100.00            97.55    28.46     1527.3    |   
May 20 2021 14:19:50:   99.99             96.30    26.70     1748.2    |   
May 20 2021 14:20:00:   100.00            97.04    25.77     1807.6    |   
May 20 2021 14:20:10:   99.99             96.78    22.88     1895.4    |   
May 20 2021 14:20:20:   99.99             96.98    24.06     1863.2    |   
May 20 2021 14:20:30:   99.99             95.90    21.17     2006.8    |   
May 20 2021 14:20:40:   99.99             97.28    23.35     1877.7    |   
May 20 2021 14:20:50:   99.99             96.29    24.46     1844.2    |   
May 20 2021 14:21:00:   99.98             96.27    22.81     1933.5    |   
May 20 2021 14:21:10:   99.99             96.15    23.20     1930.7    |   
May 20 2021 14:21:20:   100.00            96.03    19.15     2069.5    |   
May 20 2021 14:21:30:   99.99             96.14    20.80     1979.1    |   
May 20 2021 14:21:40:   100.00            95.60    16.87     2176.9    |   
May 20 2021 14:21:50:   99.99             95.93    21.92     1976.4    |   
May 20 2021 14:22:00:   99.99             95.87    20.77     2021.2    |   
May 20 2021 14:22:10:   99.99             95.34    20.68     1852.3    |   
May 20 2021 14:22:20:   99.98             95.48    19.41     2097.4    |   
May 20 2021 14:22:30:   100.00            96.25    20.08     2022.4    |   
May 20 2021 14:22:40:   99.99             98.13    27.46     1752.5    |   
May 20 2021 14:22:50:   99.99             97.72    32.47     1601.8    |   
May 20 2021 14:23:00:   100.00            95.91    24.59     1905.0    |   
May 20 2021 14:23:10:   99.98             96.85    22.18     1944.1    |   
May 20 2021 14:23:20:   100.00            97.11    23.40     1916.5    |   
May 20 2021 14:23:30:   100.00            96.45    20.39     1980.2    |   
May 20 2021 14:23:40:   100.00            96.75    24.23     1857.3    |   
May 20 2021 14:23:50:   99.99             96.91    23.79     1887.9    |   
May 20 2021 14:24:00:   100.00            96.30    19.11     2080.6    |   
May 20 2021 14:24:10:   99.99             96.70    24.99     1872.0    |   
May 20 2021 14:24:20:   99.99             98.58    33.35     1632.9    |   
May 20 2021 14:24:30:   99.97             96.13    23.06     1748.5    |   
May 20 2021 14:24:40:   99.99             96.18    22.88     1972.4    |   
May 20 2021 14:24:50:   100.00            97.72    31.80     1606.8    |   
May 20 2021 14:25:00:   100.00            96.53    22.80     1946.4    |   
May 20 2021 14:25:10:   99.99             97.23    25.56     1789.0    |   
May 20 2021 14:25:20:   99.99             94.92    17.37     2195.2    |   
May 20 2021 14:25:30:   99.99             95.75    19.38     2054.9    |   
May 20 2021 14:25:40:   100.00            94.77    18.76     2095.7    |   
May 20 2021 14:25:50:   100.00            96.41    19.12     2082.0    |   
May 20 2021 14:26:00:   100.00            97.26    19.76     2027.7    |   
May 20 2021 14:26:10:   99.99             94.68    16.85     2212.7    |   
May 20 2021 14:26:20:   99.99             95.99    21.58     1933.3    |   
May 20 2021 14:26:30:   99.97             94.76    20.44     2017.0    |   
May 20 2021 14:26:40:   99.99             96.35    19.69     2016.9    |   
May 20 2021 14:26:50:   100.00            96.21    18.31     2090.1    |   
May 20 2021 14:27:00:   100.00            96.17    18.64     2071.2    |   
May 20 2021 14:27:10:   99.98             94.94    14.54     2338.7    |   
May 20 2021 14:27:20:   99.99             95.56    18.21     2137.7    |   
May 20 2021 14:27:30:   99.99             95.02    16.69     2219.0    |   
May 20 2021 14:27:40:   99.99             96.01    18.66     2093.7    |   
May 20 2021 14:27:50:   99.98             94.92    18.34     1958.9    |   
May 20 2021 14:28:00:   99.99             94.75    26.34     1831.3    |   
May 20 2021 14:28:10:   99.99             95.99    18.41     2128.0    |   
May 20 2021 14:28:20:   100.00            95.16    7.64      2726.9    |   
May 20 2021 14:28:30:   97.80             77.90    7.07      2877.8    |   
avg                 :   99.00             95.00    20.00     2033.0    |   
max                 :   100.00            98.58    33.35     2877.8    |  

The test was then repeated calling the EXEC_ARG code.

Results - Client method EXEC_ARG

Log-analyzer> histogram -h re-repl -f 'May 20 2021 13:21:40' -d 710 -p 1000
~~~~~~~~~~~~~~~~~~~~~~~~re-repl Latency (Page-1)~~~~~~~~~~~~~~~~~~~~~~~~
NODE                :   bb9070011ac4202   .        .         .         |   
.                   :   % >1ms            % >8ms   % >64ms   ops/sec   |   
May 20 2021 13:22:10:   99.94             87.91    6.25      3202.5    |   
May 20 2021 13:22:20:   99.88             85.98    3.26      3620.1    |   
May 20 2021 13:22:30:   99.91             87.25    5.04      3282.6    |   
May 20 2021 13:22:40:   99.94             87.35    4.64      3496.0    |   
May 20 2021 13:22:50:   99.94             88.52    4.62      3394.6    |   
May 20 2021 13:23:00:   99.96             88.76    5.59      3240.6    |   
May 20 2021 13:23:10:   99.95             91.78    7.48      2944.0    |   
May 20 2021 13:23:20:   99.97             89.88    6.33      3023.5    |   
May 20 2021 13:23:30:   99.94             88.33    7.37      3047.2    |   
May 20 2021 13:23:40:   99.96             90.79    6.74      3053.2    |   
May 20 2021 13:23:50:   99.97             92.79    7.11      2875.4    |   
May 20 2021 13:24:00:   99.95             90.27    6.67      3027.8    |   
May 20 2021 13:24:10:   99.96             92.92    7.76      2858.3    |   
May 20 2021 13:24:20:   99.91             89.29    5.36      3280.7    |   
May 20 2021 13:24:30:   99.97             90.81    6.53      3002.6    |   
May 20 2021 13:24:40:   99.95             88.64    5.97      3236.4    |   
May 20 2021 13:24:50:   99.92             88.62    5.77      3197.1    |   
May 20 2021 13:25:00:   99.95             90.29    5.49      3150.7    |   
May 20 2021 13:25:10:   99.95             90.45    6.92      3068.1    |   
May 20 2021 13:25:20:   99.94             89.46    5.27      2961.4    |   
May 20 2021 13:25:30:   99.98             92.55    6.08      3050.9    |   
May 20 2021 13:25:40:   99.94             93.71    9.96      2719.6    |   
May 20 2021 13:25:50:   99.95             89.66    6.91      2941.8    |   
May 20 2021 13:26:00:   99.94             90.36    7.32      2992.6    |   
May 20 2021 13:26:10:   99.96             92.01    7.55      2868.0    |   
May 20 2021 13:26:20:   99.94             90.15    5.65      3160.2    |   
May 20 2021 13:26:30:   99.94             90.13    4.94      3279.6    |   
May 20 2021 13:26:40:   99.94             89.21    4.36      3331.8    |   
May 20 2021 13:26:50:   99.94             89.54    5.10      3353.5    |   
May 20 2021 13:27:00:   99.93             91.34    6.95      2930.1    |   
May 20 2021 13:27:10:   99.94             87.89    6.94      3163.2    |   
May 20 2021 13:27:20:   99.95             91.03    6.53      3040.1    |   
May 20 2021 13:27:30:   99.95             90.33    6.19      3113.6    |   
May 20 2021 13:27:40:   99.94             89.24    5.13      3235.9    |   
May 20 2021 13:27:50:   99.98             91.41    7.21      2956.5    |   
May 20 2021 13:28:00:   99.96             89.71    5.63      3185.7    |   
May 20 2021 13:28:10:   99.95             88.99    5.28      3264.4    |   
May 20 2021 13:28:30:   99.95             88.92    5.76      2939.1    |   
May 20 2021 13:28:40:   99.99             90.11    6.44      3099.8    |   
May 20 2021 13:28:50:   99.95             87.82    5.01      3306.4    |   
May 20 2021 13:29:00:   99.98             91.66    8.42      2808.9    |   
May 20 2021 13:29:10:   100.00            97.27    22.43     1903.4    |   
May 20 2021 13:29:20:   99.98             93.07    10.76     2629.1    |   
May 20 2021 13:29:30:   99.97             90.93    8.67      2826.0    |   
May 20 2021 13:29:40:   99.96             91.56    7.97      2819.5    |   
May 20 2021 13:29:50:   99.98             91.08    8.29      2780.1    |   
May 20 2021 13:30:00:   99.96             91.24    8.86      2812.4    |   
May 20 2021 13:30:10:   99.98             93.20    10.84     2581.0    |   
May 20 2021 13:30:20:   99.98             93.86    11.49     2519.3    |   
May 20 2021 13:30:30:   99.93             90.30    7.37      2970.0    |   
May 20 2021 13:30:40:   99.95             90.48    6.25      3002.7    |   
May 20 2021 13:30:50:   99.96             89.82    6.72      3037.8    |   
May 20 2021 13:31:00:   99.97             91.52    9.99      2712.1    |   
May 20 2021 13:31:10:   99.99             93.33    11.46     2570.4    |   
May 20 2021 13:31:20:   99.97             94.10    16.79     2239.3    |   
May 20 2021 13:31:30:   99.99             92.52    9.25      2730.7    |   
May 20 2021 13:31:40:   99.97             93.11    9.44      2697.2    |   
May 20 2021 13:31:50:   99.97             91.12    7.13      2995.3    |   
May 20 2021 13:32:00:   99.98             94.84    9.34      2386.9    |   
May 20 2021 13:32:10:   99.94             91.25    6.51      2959.7    |   
May 20 2021 13:32:20:   99.97             90.56    6.14      3063.4    |   
May 20 2021 13:32:30:   99.95             91.97    6.93      2949.7    |   
May 20 2021 13:32:40:   99.98             93.59    11.87     2499.6    |   
May 20 2021 13:32:50:   99.94             91.30    11.72     2577.8    |   
May 20 2021 13:33:00:   99.98             95.53    16.98     2307.8    |   
May 20 2021 13:33:10:   99.98             94.55    7.32      2824.0    |   
May 20 2021 13:33:20:   99.86             88.75    6.04      2975.4    |   
avg                 :   99.00             90.00    7.00      2955.0    |   
max                 :   100.00            97.27    22.43     3620.1    |  

Summary of Results

The results are summarised in the table below.

Method Average OPS/Sec Max OPS/sec Total Time Elapsed
Basic Scan and Touch 2642 3133 740s
UDF Peek 3544 4459 550s
Client STMT 2033 2877.8 960s
Client EXEC ARG 2955 3620.1 670s

The results show that the simplest method, the UDF Peek is fastest and this is no real surprise. This does not necessarily imply that this method is always preferable. The biggest potential weakness of any UDF-based approach however is an operational one. The UDFs require permissions to register and run, most notably the data-admin role which is necessary to register a new UDF. It is quite possible that access to these roles will not be available to operations teams or may require a change request to be in place. Some environments will not permit UDFs at all within the cluster.

A big drawback of the scan and touch based approach is that although it is simple in concept and perhaps more familiar than the peek method, it will update the generation of the record. A touch will also cause records to be re-shipped by XDR if XDR is configured on the system.

In situations like these, the client based solutions, although slightly slower, may offer a solution that is, ultimately, more convenient. If operational staff are less comfortable with client coding, tools like the Jupyter notebook make running code in quick and easy.

Caveats

All of the methods outlined here will, of course, update the last update time of the record concerned and any bins within the record. This is unavoidable however it will then affect behaviour if Aerospike Expressions are being used to process records based on metadata. Furthermore, if XDR bin-policy is being used to control which bins are shipped to remote datacenters, this may be affected by the change in last update time of the record and bins.

All methods rely on a scan to feed records into whatever replicates the record. Scans, even in the post-Aerospike 4.7 scan architecture can be resource heavy and potentially disruptive to normal transaction load. Furthermore they are a limited quantity within the system and running these scans could interfere with scans being run as part of the application. For this reason it is best to run re-replication during off peak load times.

It is worth mentioning that during this test, to measure the 4 methods of re-replication on a level playing field, no client load was running during re-replication. Client load would be causing re-replication in a natural manner as records were read. This would mean that replication would happen faster than shown here as the re-replication would only be required on records that had not been replicated naturally by the ongoing read load.

Notes

  • This article describes cold start re-replication in detail.
  • If XDR is configured for the cluster that requires re-replication then a rewind will have the effect of re-replicating the records. However these would also be shipped to remote datacenteers.
  • This document describes management of scans within an Aerospike cluster.
  • Aerospike version 5.7 will soon ship with a statistic and associated log line that will indicate the number of unreplicated records within the cluster.

Keywords

RE-REPLICATION COLD START STRONG CONSISTENCY

Timestamp

May 2021