Diagnosing XDR partitions that keep going back into recovery

Audience: DBAs and SREs who run Aerospike XDR.
Applies to: Aerospike Database Enterprise 5.7 to 8.2. recovery-threads exists in 8.1.1 and later.

Symptom

After a burst of writes, XDR falls behind a destination that is otherwise healthy, and it doesn't catch up:

• lag keeps growing for hours, even though the destination accepts records normally and there are no shipping retries.
• recoveries keeps increasing, but recoveries_pending (the "Recoveries Pending" column in asadm -e "info xdr") barely falls.
• The nodes that lag are the ones whose transaction queues reached transaction-queue-limit during the burst.

A partition whose transaction queue is discarded has to catch up through recovery (an index scan). When recoveries don't clear, there are three possible reasons, and the fixes differ. This article shows how to tell them apart.

For how the queue overflows in the first place and how to size transaction-queue-limit, see the companion article, Sizing XDR transaction-queue-limit and detecting queue overflow before it forces recoveries.

1. How a master partition moves through recovery

XDR tracks a state for each partition and DC. xdr-dc-state shows it as one letter, and the xdr log context at detail level logs each change by name.

A partition that overflows goes T → B → R → A, or straight from B back to T when the queue still covers the gap. From A it goes one of two ways:

• Back to T, when the transaction queue still holds every write made since the scan started. The partition is caught up.
• Back to R for another round, when the queue was discarded again while the scan was running. The scan covered writes up to its start. The queue no longer holds the writes made after that, so XDR scans again.

Three details matter for diagnosis:

• The queue keeps filling during recovery. New writes to the partition are queued while the scan runs. If the queue reaches the limit during the scan, it is discarded again, with no state change and no log line.
• The counters move at different points. recoveries goes up by one each time a scan round finishes, including a round that leads to another round. recoveries_pending goes up by one when a partition goes from B to R, and down by one only when it returns to T.
• lag falls only when a partition returns to T. A node's lag follows its furthest-behind master partition, so it can stay high while most partitions are caught up.

Replica partitions also log state changes (TRANSACTION -> RECOVERY_INCOMPLETE, state I). They don't run recovery, so leave them out of this diagnosis.

2. The three patterns

The patterns can occur together, on different partitions of the same node.

3. Collecting the evidence

Replace DC1 and test with your DC and namespace names. Add -U <user> -P and your TLS options to asadm and asinfo as needed.

Start here. Pick one lagging node, and run the asinfo and grep commands in this section on that node (-h <node-ip> -p 3000). Turn on the detail log there now, so it covers the same 30 minutes as the counters in 3.1:

asinfo -v "log-set:id=0;xdr=detail"

The setting is dynamic, applies to that node only and is lost on restart. If your log sink isn't id 0, find it with asinfo -v "logs".

3.1 Counters over time

Use the watch command in asadm to take a reading every 60 seconds, 30 times, for every node at once. Each reading starts with a timestamp. At the Admin> prompt in interactive asadm:

watch 60 30 show statistics xdr namespace for test for DC1 like lag recoveries throughput

like recoveries shows both recoveries and recoveries_pending. throughput above 0 shows XDR is still shipping. watch 60 30 info xdr for DC1 gives a shorter view with lag and Recoveries Pending, but not recoveries.

To save the readings to a file, run the same command non-interactively:

asadm -e "watch 60 30 show statistics xdr namespace for test for DC1 like lag recoveries throughput" | tee xdr-recoveries.txt

Compare the change in recoveries with the change in recoveries_pending over the whole window:

• recoveries +20, recoveries_pending −20: slow scan.
• recoveries +20, recoveries_pending −2: repeat rounds or drop-back. The partition states and the log tell them apart.
• recoveries +0: recovery isn't progressing on this node. Collect the evidence in 3.2 and 3.3, then contact Support (section 5).

3.2 Partition states

Count master (M) and replica (P) partitions by state:

asinfo -v "xdr-dc-state:dc=DC1;namespace=test" | grep -oE '[ 0-9]{4}:[MP]:[A-Z]:' | awk -F: '{ c[$2 ":" $3]++ } END { for (k in c) print k, c[k] }'

Take two readings a few minutes apart. Masters in M:B while the destination is healthy mean queues are still overflowing; the log (3.3) shows whether those are drop-backs. Masters staying in M:R and M:A with few in M:B mean slow scans or repeat rounds.

On releases before 7.2.0.22, 8.0.0.20 and 8.1.2.5, long namespace names can truncate xdr-dc-state rows. The state letters this command counts are not affected.

3.3 The detail log

After 30 minutes, turn the detail log off:

asinfo -v "log-set:id=0;xdr=info"

Each state change is one line:

{test:3557} DC DC1 role M -> M, state POST_RECOVERY_JOB -> RECOVERY

Count each transition for master partitions (adjust the log path). If the node logs to the journal instead of a file, pipe journalctl -u aerospike -a -o cat into the grep commands below and omit the file name:

grep -oE "role M -> M, state [A-Z_]+ -> [A-Z_]+" /var/log/aerospike/aerospike.log | sort | uniq -c

To confirm drop-back, follow single partitions: a partition that logs POST_RECOVERY_JOB -> TRANSACTION and later TRANSACTION -> PRE_RECOVERY has dropped back. This lists those partitions in log order and counts them:

grep -E "role M -> M, state (POST_RECOVERY_JOB -> TRANSACTION|TRANSACTION -> PRE_RECOVERY)" /var/log/aerospike/aerospike.log | grep -oE '\{[^}]+\} DC .*' | awk '{ p = $1 } /POST_RECOVERY_JOB -> TRANSACTION/ { caught[p] = 1; next } caught[p] { print p; n++ } END { print n + 0, "drop-backs" }'

Only the first discard of a partition is logged while it waits in B, so the counts are a lower bound.

4. What to do for each pattern

All three settings below are dynamic. set-config changes are lost on restart, so add the final values to aerospike.conf once XDR has caught up. Don't put both recovery-threads above 1 and max-recoveries-interleaved above 0 in the file: the node won't start, and logs CRITICAL (xdr) with can't set non-zero 'max-recoveries-interleaved' if 'recovery-threads' > 1.

Avoid restarting nodes while XDR is behind: a restarted node puts every partition it masters through recovery.

4.1 Slow scan: add recovery threads

Before 8.1.1, recovery has one thread per DC and can't be made faster. Avoid restarts and let it finish, and plan an upgrade if this recurs. If rounds also repeat, go to section 4.2.

On 8.1.1 and later, recovery-threads (DC context, default 1, range 1 to 32) sets how many threads scan partitions for recovery for that DC.

First check max-recoveries-interleaved in asinfo -v "get-config:context=xdr;dc=DC1". If it is above 0, set it to 0, because recovery-threads is refused (ERROR:4) while it is set:

asinfo -v "set-config:context=xdr;dc=DC1;max-recoveries-interleaved=0"

Then raise recovery-threads, for example to 4. More threads help most when CPU and storage have headroom and recovery scans many records but ships few of them. If CPU or storage is already busy, extra threads add contention without making recovery faster, so watch client latency:

asinfo -v "set-config:context=xdr;dc=DC1;recovery-threads=4"

Check: recoveries rises faster within about 10 minutes, and recoveries_pending starts falling.

4.2 Repeat rounds: shorten each scan first, then raise the queue limit

A round repeats when the queue fills up before the scan finishes.

Step 1: shorten each scan (the time one partition's scan stays open). On 8.1.1 and later, add recovery threads (section 4.1). Each thread finishes one partition before it takes the next, so scans stay short and most repeat rounds stop.

Before 8.1.1, set max-recoveries-interleaved. With the default 0, the single recovery thread works through all pending partitions in turn, so every scan stays open for a long time. A value above 0 limits how many partitions are scanned at once. 1 scans one partition to the end before starting the next, so each scan is as short as possible:

asinfo -v "set-config:context=xdr;dc=DC1;max-recoveries-interleaved=1"

Step 2: if rounds still repeat, raise the queue limit (section 4.3), so the queue lasts longer than the scan.

Check: with detail logging on again, POST_RECOVERY_JOB -> RECOVERY lines stop, and recoveries_pending starts falling.

4.3 Drop-back: raise the queue limit

transaction-queue-limit (DC namespace context, default 16384, a power of 2 from 1024 to 1048576) sets how many writes a partition's queue holds before it is discarded. Raise it to the next power of 2, for example 32768 (double the default):

asinfo -v "set-config:context=xdr;dc=DC1;namespace=test;transaction-queue-limit=32768"

Check: with detail logging on again, TRANSACTION -> PRE_RECOVERY lines stop, and masters stop appearing in M:B.

The limit applies to every queue on the node, master and replica, so memory grows with it. See the companion article for sizing and memory cost, and for cases where a larger limit doesn't help because writes arrive faster than XDR can ship them.

5. When to contact Support

If recoveries_pending and lag aren't falling within about 30 minutes of a change, open a case and send:

• a collectinfo from the cluster;
• the watch output from section 3.1;
• the two partition-state counts from section 3.2, with the node they came from;
• the log from the node you chose in section 3, covering the whole window;
• the time of the write burst, and any configuration changes made since.

References

• Sizing XDR transaction-queue-limit and detecting queue overflow before it forces recoveries
• XDR record shipment lifecycle, including recovery mode
• XDR configuration reference: transaction-queue-limit
• XDR configuration reference: recovery-threads
• XDR configuration reference: max-recoveries-interleaved
• How does max-recoveries-interleaved work?
• XDR metrics reference: recoveries_pending