trepctl perf
The trepctl perf command outputs performance information on a stage by stage basis from the current replicator. The information has been extracted from the existing replicator
status, task and stage information available through other commands and requests, but reformatted, and with values calculated to make identifying specific performance metrics quicker.
trepctl [-service <servicename>] perf [ options ]
Where:
| Option | Description | Version |
|---|---|---|
-c n | Used with the -r option to refresh the services display n number of times. | 7.0.2 |
-r n | Auto-Refresh the output every n seconds, where n is an integer value in seconds. Refresh until CTRL+C is pressed |
For example, on a typical extraction replicator:
Statistics since last put online 9265.385s ago
Stage | Seqno | Latency | Events | Extraction | Filtering | Applying | Other | Total
binlog-to-q | 1604 | 8.779s | 14 | 60.173s | 0.109s | 0.015s | 0.004s | 60.301s
Avg time per Event | 4.298s | 0.008s | 0.000s | 0.001s | 4.307s
Filters in stage | colnames -> pkey
q-to-thl | 1604 | 10.613s | 14 | 56.858s | 0.020s | 5.247s | 0.028s | 62.153s
Avg time per Event | 4.061s | 0.001s | 0.002s | 0.375s | 4.440s
Filters in stage | enumtostring -> settostring
On an applier:
Statistics since last put online 38.418s ago
Stage | Seqno | Latency | Events | Extraction | Filtering | Applying | Other | Total
remote-to-thl | 3246 | 1.143s | 42 | 37.831s | 0.001s | 0.403s | 0.011s | 38.246s
Avg time per Event | 0.901s | 0.000s | 0.000s | 0.010s | 0.911s
thl-to-q | 3246 | 1.209s | 1654 | 37.113s | 0.005s | 1.090s | 0.098s | 38.306s
Avg time per Event | 0.022s | 0.000s | 0.000s | 0.001s | 0.023s
q-to-dbms | 3235 | 3.746s | 1644 | 22.226s | 0.019s | 15.242s | 0.338s | 37.825s
Avg time per Event | 0.014s | 0.000s | 0.000s | 0.009s | 0.023s
Filters in stage | mysqlsessions -> pkey
Available in 7.2.0 and later.
On an applier with Parallel apply enabled, the output for the q-to-dbms stage will show multiple lines per parallel channel, for example:
Statistics since last put online 4.415s ago
Stage | Seqno | Latency | Events | Extraction | Filtering | Applying | Other | Total
remote-to-thl | 26 | 0.467s | 27 | 0.071s | 0.000s | 0.027s | 0.000s | 0.098s
Avg time per Event | 0.003s | 0.000s | 0.000s | 0.001s | 0.004s
thl-to-q | 26 | 1.295s | 27 | 0.118s | 0.000s | 0.813s | 0.000s | 0.931s
Avg time per Event | 0.004s | 0.000s | 0.000s | 0.030s | 0.034s
q-to-dbms.0 | 26 | 1.311s | 26 | 0.905s | 0.000s | 0.035s | 0.001s | 0.941s
Avg time per Event | 0.035s | 0.000s | 0.000s | 0.001s | 0.036s
q-to-dbms.1 | 26 | 1.305s | 27 | 0.867s | 0.000s | 0.066s | 0.001s | 0.934s
Avg time per Event | 0.032s | 0.000s | 0.000s | 0.002s | 0.035s
q-to-dbms.2 | 26 | 1.305s | 13 | 0.903s | 0.000s | 0.030s | 0.002s | 0.935s
Avg time per Event | 0.069s | 0.000s | 0.000s | 0.002s | 0.072s
The individual statistics shown are as follows:
-
All statistics within the replicator are reset when the replicator goes
ONLINE. The statistics shown are therefore displayed relative to the current uptime for the replicator. -
For each stage, the following information is shown:
- Stage name
- Seqno — this is the current
SEQNOnumber for the specified stage. A difference in sequence numbers is possible (as seen in the applier example above) during startup or synchronisation. - Latency — the latency of this stage compared to the commit time of the original transaction.
- Events — the number of THL events processed by this stage.
-
Statistics are then shown for each stage, two rows, first for the time to process all of the specified events, and then an average processing time for the events processed during that time within that stage. The individual statistics shown are as follows:
- Extraction — the time taken to extract the event from the current source. On an extractor, this is the source database (for example, the binary log in MySQL). On other stages this is the time to read from disk or the remote replicator the THL event.
- Filtering — the time taken to process the events through the filters configured in the specified stage.
- Applying — the time taken to apply the event to the end of the stage, whether that is to THL on disk, the next queue in preparation for the next stage, or the target database.
- Other — the time taken for other parts of the stage process, this includes waiting for thread management, updating internal structures, and recording information in the target datasource system, such as trep_commit_seqno.
-
Filters in stage — The list of filters configured for this stage in the order in which they are applied to the event.
In the event that the replicator is currently OFFLINE, no statistics are displayed:
shell> trepctl perf
Currently not online; performance stats not available
State: Safely Offline for 6.491s
Using -c and -r
For convenience, the performance display can be set to refresh with a configured interval using the -r option, passing a value in seconds
for the auto-refresh. This can be cancelled by using CTRL+C.
shell> trepctl perf -r 5
The -c option can also be used with the -r option to limit the number of refresh iterations. For example, the command below
would refresh every 5 seconds for a total of 10 iterations before exiting to the command prompt:
shell> trepctl perf -c 10 -r 5