How To use key-busy logging to identify a hot key

Audience: DBAs and SREs troubleshooting hot keys (fail_key_busy, error 14 KEY_BUSY).
Applies to: Aerospike Database 6.4.0.0 and later.

Context

When clients receive error 14 (KEY_BUSY) and the namespace statistic fail_key_busy is increasing, a node is refusing transactions because too many are already queued on the same record. Setting the key-busy log context to detail makes the node log each refused transaction's digest, the operation, and where it came from.

The key-busy log context is available in Aerospike Database 6.4.0.0 and later. It is not in 6.3 or earlier releases.

Unlike rw-client logging, key-busy logging records only the transactions that were refused, and it groups identical lines. Its output is small, it points straight at the record that is over the limit, and it covers every source of transactions: single-record and batch requests, background UDFs and operations, and transactions forwarded from other nodes.

Warning (Fix pending): Do not use this method on Aerospike Database Enterprise 8.0.0.0 or later if any strong-consistency namespace uses multi-record transactions (MRTs). With key-busy at detail, a node stops with CRITICAL (rw): ... unexpected transaction origin 8 (or 9, 10) when the server finishes an abandoned transaction on a record that is already over transaction-pending-limit. The node that takes over the record can then stop the same way, which can leave the namespace unavailable. On those clusters, use rw-client logging instead. Namespaces that do not use transactions are not affected.

What is logged

A transaction is logged when it is refused because its record already has more than transaction-pending-limit transactions waiting (default 20). Only transactions that wait in the node's rw-hash can be refused:

• All writes: updates, deletes, UDFs, batch writes, and background UDFs and operations.
• Reads that must wait for another node: reads in a strong-consistency namespace while a write to the same record is still replicating, linearized reads, and reads with read consistency level all during migrations.

Ordinary reads in an AP namespace never wait, so they are never refused or logged. To find hot keys for those reads, use How To identify read hotkeys.

Method

1. Find the node with the hot key

Run this twice, a few seconds apart, and look for the node where fail_key_busy is increasing:

asadm -e "show statistics namespace like fail_key_busy"

The node's log also shows the count every 10 seconds:

INFO (info): (ticker.c:1209) {test} special-errors: key-busy (39070355,0) record-too-big 0 lost-conflict (0,0)

2. Turn on key-busy logging

List the log sinks to find the ID of the sink to use:

asinfo -v 'logs'

The output lists each sink as <id>:<path>, for example 0:/var/log/aerospike.log;1:stderr. Turn on detail for that sink on every node:

asadm --enable -e "asinfo -v 'log-set:id=0;key-busy=detail'"

To turn it on for one node only, run asinfo -v 'log-set:id=0;key-busy=detail' on that node.

3. Collect, then turn it off

Leave it on for 30 to 60 seconds while fail_key_busy is increasing, then set it back on every node:

asadm --enable -e "asinfo -v 'log-set:id=0;key-busy=info'"

Confirm that every node returns key-busy:INFO:

asadm --enable -e "asinfo -v 'log/0/key-busy'"

A log-set change lasts only until the node restarts.

4. Read the log lines

Each new combination of namespace, digest, operation and origin is logged as soon as it occurs:

Nov 09 2026 19:08:05 GMT: DETAIL (key-busy): (rw_request_hash.c:224) {test} 893023f6f45f1f1379391d5396fa1ad2fcc88cac write from 172.17.0.5:36892

Further occurrences are counted, not logged. Every 10 seconds (ticker-interval) the node writes the count for each combination seen in that interval:

Nov 09 2026 19:08:16 GMT: DETAIL (key-busy): (rw_request_hash.c:224) (repeated:1227) {test} 893023f6f45f1f1379391d5396fa1ad2fcc88cac write from 172.17.0.5:36892

The fields after the namespace are:

Digest

The 20-byte record digest, in hex.

Operation

read, write, delete or udf, or batch-sub-read, batch-sub-write, batch-sub-delete or batch-sub-udf for a record in a batch request.

Origin

The client's address:port for client and batch requests. proxy means the transaction was forwarded by another node, usually because the client sent it to a node that is not the record's master. bg-udf and bg-ops are background UDFs and background operations started by a query or scan.

5. Rank the hot keys

On the node with the hot key, count refusals by namespace and digest:

grep '(key-busy)' /var/log/aerospike.log | awk '{
  for (i = 1; i <= NF; i++) if ($i ~ /^\{/) break
  n = ($(i-1) ~ /^\(repeated:/) ? substr($(i-1), 11) + 0 : 1
  count[$i " " $(i+1)] += n
} END { for (k in count) print count[k], k }' | sort -rn | head -10

Example output:

5721386 {test} 893023f6f45f1f1379391d5396fa1ad2fcc88cac
1876554 {test} d78242de03c38d5dbb720b96b12069c4e1b466df

To see which operations and client addresses are involved, count by digest, operation and client address (without the port):

grep '(key-busy)' /var/log/aerospike.log | awk '{
  for (i = 1; i <= NF; i++) if ($i ~ /^\{/) break
  n = ($(i-1) ~ /^\(repeated:/) ? substr($(i-1), 11) + 0 : 1
  origin = $(i+4); sub(/:[0-9]+$/, "", origin)
  count[$(i+1) " " $(i+2) " " origin] += n
} END { for (k in count) print count[k], k }' | sort -rn | head -10

Example output:

5721386 893023f6f45f1f1379391d5396fa1ad2fcc88cac write 172.17.0.5
1876554 d78242de03c38d5dbb720b96b12069c4e1b466df batch-sub-write 172.17.0.6

If the node logs to journald, replace grep '(key-busy)' /var/log/aerospike.log with journalctl -u aerospike --since '<start time>' | grep '(key-busy)'.

6. Find the record's set

debug-record-meta shows the set name and which nodes hold the record. With security enabled, it needs a user whose role includes data-admin or sys-admin.

asadm --enable -e "asinfo -v 'debug-record-meta:namespace=test;keyd=893023f6f45f1f1379391d5396fa1ad2fcc88cac'" | tr ',;' '\n\n' | grep -E 'returned|repl-ix|set-name'

Each node that holds a copy returns set-name=<set>. repl-ix=0 marks the master copy. debug-record-meta does not show the user key, so the application owner identifies the record from the set name, the client addresses and the operation.

Notes

• Counts are approximate. A (repeated:N) count includes the first occurrence, which also has its own line, so the commands can count it twice. The counts for the last interval before logging is set back to info are not written. Neither affects which key ranks first.
• One client can produce many lines. The origin includes the client's port, so each connection gets its own line. The second command removes the port.
• The volume is small. A line is written once per combination per interval, however many transactions are refused. A digest refused a million times in 10 seconds produces one (repeated:...) line.
• Versions before 6.4.0.0 have no key-busy context. They log {ns} key busy <digest> at detail in the rw context, without operation or origin, and rw at detail logs much more. Use rw-client logging on those versions.
• For mitigations once the key is known, see Why does my client return Error code 14 Hot key?

Applies To Earliest Version

6.4.0.0

Applies To Latest Version

Current Version. On Enterprise 8.0.0.0 and later, see the warning above for strong-consistency namespaces that use multi-record transactions.