Example of Hot Copy Log Message

To display hot copy logging run one of the following in a separate terminal/console before running the hot copy command:

# Text output
nuocmd show log-messages --db-name rcm-dev --log-options hotcopy

# JSON format output
nuocmd get log-messages --db-name rcm-dev --log-options hotcopy

Log Message Format

Some log messages are quite straightforward, they indicate the stage of the hot copy and an activity:

Stage1: Copy atoms hot copying from /volumes/archives/test to /volumes/backups/test-2022-04-18
Stage1: Copy dirty atoms (iteration 1) hot copying from /volumes/archives/test to /volumes/backups/test-2022-04-18

Others are more detailed. The longest message enabled by the hotcopy logging category looks like:

Hot copy 731635bb-867c-4681-b78c-1de9ef662cd3 stage 1 45.129 sec during 2196 replic msgs, waited for node 3, thread sync 1.25 sec, 4321 archive reads (195MB, 4.3MB/sec, 7.0%) 22135 writes (885MB, 19.7MB/sec, 35.7%),
171+0 journal writes (255KB, 5.6KB/sec, rd 3.3% wr 5.4%) sequence 1..171
Portions of this message are omitted when they do not apply or are zero.

Understanding this Hot Copy Log Message

The following table describes the breakdown of items within this hot copy log message:

Item Description

Hot copy 731635bb-867c-4681-b78c-1de9ef662cd3

The unique identifier for the hot copy.

stage 1

The stage or inter-stage. For more details see Hot Copy Stages.

45.129 sec

The time elapsed while performing this stage on this node.

during 2196 replic msgs

The number of replication messages received while performing this stage; this is a measure of database write load.

waited for node 3

Identifies the node (in a multi-node hot copy) which was the last to complete this inter-stage.

thread sync 1.25 sec

The time elapsed while waiting to synchronize with other threads.

4321 archive reads

The number of files read from the archive.

195MB

The total size of files read from the archive.

4.3MB/sec

The number of bytes (for archive reads) read per second.

7.0%

The percentage of time elapsed while waiting for archive reads.

22135 writes

The number of archive files written to the copy

885MB

The total size of files written to the copy.

19.7MB/sec

The number of bytes written per second.

35.7%

The percentage of time elapsed while waiting for writes.

171+0 journal writes

The number of journal files copied; the first number is for current journal files, the second number relates to the journal files which were copied after they were reaped.

255KB

The total size of journal files.

5.6KB/sec

The number of bytes copied per second.

rd 3.3%

The percentage of time elapsed while waiting for journal reads.

wr 5.4%

The percentage of time elapsed while waiting for journal writes.

sequence 1..171

The range of journal file sequence numbers copied.

lastJournalSequence 168

The journal position when no journal files were copied.

As per the note above, an item such as this may be omitted from the log message.

Hot Copy Stages

The hot copy stages and inter-stages are described as follows. The inter-stages are required during a coordinated hot copy involving more than one SM.

Stage/inter-stage Description

stage 0

The startup stage.

stage 0+

The inter-stage which waits for other nodes to complete stage 0

stage 1

Where the archive and journal are copied in the background.

stage 1+

The inter-stage waiting for other nodes to complete stage 1.

stage 2

Where commits are delayed and the last portion of the journal is copied.

stage 2+

The inter-stage waiting for other nodes to complete stage 2.

stage 3

Where the copy is finalized and the journal files marked as eligable to be reaped (deleted). The SM periodically reaps journal files that are no longer needed and will remove them during its next pass.

stage 3+

The inter-stage waiting for other nodes to complete stage 3.
If a hot copy log-message is not prefixed with Stage N, then the stage is the second item in the message - see above.