Technical Blog Post
Abstract
Let the Registry provide you performance reports
Body
Performance is an important matter. Several aspects can influence how fast (or slow) applications respond to user requests. There is a variety of tools for monitoring the application server, the database, the Java Virtual Machine, the I/O operations, the memory and so on, in order to assess performance.
For sure all that available tooling is applicable to Registry Services. The great news: the Registry has its own mechanism, enabled by default, to monitor how the operations on resources are being performed.
The monitoring covers the basic operations on Registration Records: creation, deletion and update.
For each incoming request, the Registry watches and records internally the time taken to complete the operation itself, excluding the processing time to deserialize the incoming RDF payload (transforming XML / JSON data into internal Registry objects) and to serialize the response (converting the results to XML / JSON data).
For batch requests, following the OSLC Automation specification, each atomic creation / delete / update operation is monitored separately.
The Registry keeps a history of performance data for operations for the last 7 days of the current run. If the application is restarted, the history starts from scratch and will have the data captured by the monitoring of the new operation requests.
Getting performance data reports
You might be wondering how to have access to all the performance data gathered by the Registry.
The stats CLI comes on the scene. With a call along with a few parameters, the CLI generates a report with the summary of the performance data gathered by the Registry.
You can be presented with a report from either the last minutes (up to 59), or the last hours (up to 23) or the last days (up to 7) of operations processed by the Registry.
Refer to the http://pic.dhe.ibm.com/infocenter/tivihelp/v3r1/topic/com.ibm.psc.doc_1.1.0/rs_original/cli/rs_r_performance_stat_command.html for education on the CLI syntax.
An example of report, for operations from the last minutes (command: frs stats -minutes 30):
AGGREGATE
==========
Operation: create
Records per minutes: 422
Records per second: 7.03
Average duration for record create operation: 274 ms
Min duration for create operation: 3 ms
Max duration for create operation: 1332 ms
Operation: delete
Records per minutes: 424
Records per second: 7.07
Average duration for record delete operation: 457 ms
Min duration for delete operation: 16 ms
Max duration for delete operation: 7022 ms
Operation: update
Records per minutes: 30
Records per second: 0.5
Average duration for record update operation: 541 ms
Min duration for update operation: 171 ms
Max duration for update operation: 1737 ms
All operations having start time within the period are regarded in the report.
For each operation type having performance data in the period, we get the rate (per minutes, hours or days, depending on the period indicated in the parameters on the CLI call) of Registration Records processed, the rate per second and the average, minimum and maximum durations in miliseconds.
The aggregate report is the standard CLI output, nice for learning about the past overall throughput, the number of operations completed and some statistics.
Detailed reports
What is even nicer is the possibility of getting a more detailed report, having the aggregate report plus the overall score broken down into smaller periods.
Below, an example of a detailed report for the last 5 minutes of the Registry lifetime (command: frs stats -minutes 5 -verbose):
AGGREGATE
==========
Operation: create
Records per minutes: 2816
Records per second: 46.93
Average duration for record create operation: 129 ms
Min duration for create operation: 8 ms
Max duration for create operation: 1721 ms
MINUTES 1
==========
Operation: create
Records per minutes: 248
Records per second: 4.13
Average duration for record create operation: 223 ms
Min duration for create operation: 11 ms
Max duration for create operation: 858 ms
MINUTES 2
==========
Operation: create
Records per minutes: 428
Records per second: 7.13
Average duration for record create operation: 241 ms
Min duration for create operation: 13 ms
Max duration for create operation: 1594 ms
MINUTES 3
==========
Operation: create
Records per minutes: 603
Records per second: 10.05
Average duration for record create operation: 154 ms
Min duration for create operation: 11 ms
Max duration for create operation: 1721 ms
MINUTES 4
==========
Operation: create
Records per minutes: 850
Records per second: 14.17
Average duration for record create operation: 90 ms
Min duration for create operation: 8 ms
Max duration for create operation: 1458 ms
MINUTES 5
==========
Operation: create
Records per minutes: 687
Records per second: 11.45
Average duration for record create operation: 52 ms
Min duration for create operation: 9 ms
Max duration for create operation: 1591 ms
The overall data still comes first, but this time the report has more sections, one for each minute included in the whole period having information presented in a layout similar to the aggregate section.
The verbose report is a handy source for understanding the distribution of workloads along the Registry history and for identifying peaks.
Details report structure
The detailed report structure depends on the period indicated in the CLI call:
a) Last minutes report
An overall section for the whole period
AGGREGATE
<data>
A separate MINUTES section for each minute in the period
MINUTES 1
<data>
MINUTES 2
<data>
...
b) Last hours report
An overall section for the whole period
AGGREGATE
<data>
A section for all the last minutes not within a full hour. For example, if it's 11:34 PM, the last 34 minutes are regarded
MINUTES 1
<data>
A separate HOURS section for each full hour in the period
HOURS 1
<data>
HOURS 2
<data>
...
c) Last days report
An overall section for the whole period
AGGREGATE
<data>
A section for all the last minutes not within a full hour. For example, if it's 11:34 PM, the last 34 minutes are regarded
MINUTES 1
<data>
A section for all the last hours not within a full day. For the same example of 11:34 PM, the last 23 full hours are regarded
HOURS 1
<data>
A separate DAYS section for each full day in the period
DAYS 1
<data>
DAYS 2
<data>
...
UID
ibm11275808