v3.4 Output

Introduction

Standard Output

The stdout log messages are filtered with log level. Any with level less than "INFO" are not shown. Also only the messages falling into one of the following categories are passing to the stdout:

• Messages
• Error Messages
• Periodic Metrics Snapshots Per Step
• Total Metrics Per Step

Metrics Table

The periodic metrics standard output is formatted as a table:

Note:

• Metrics table width is 120 symbols
• By default, metrics table header is repeated every 20 records

Metrics Table Columns

• Step Name

  The configured step name. Timestamp value is used if not configured obviously. Note that only last 12 characters are displayed in the table.

• Timestamp

  The datetime of the record output.

• Operation Type

  May be N (Noop), C (Create), R (Read), U (Update) or D (Delete). Colored for readability.

• Concurrency x Drivers

  The configured concurrency level and the count of the storage drivers used to perform a load. The effective concurrency level is a product of configured concurrency and the drivers count.

• Count/Success

  The count of the items processed sucessfully.

• Count/Failed

  The count of the items processed with a failure.

• Step Time [s]

  The test step elapsed time in seconds. Note that the step elapsing more than 11.574 days will cause the cell overflow as far as only 6 characters are available for the output.

• Last Rate/[op/s]

  The moving average operations per second rate for the last 10 seconds period.

• Last Rate/[MB/s]

  The moving average megabytes per second rate for the last 10 seconds period.

• Mean Latency [us]

  The last mean latency measured in the microseconds.

• Mean Duration [us]

  The last mean operation duration measured in the microseconds.

Load Step Summary

At the end of each load step the total results are displayed:

2017-06-01T18:05:45,271 I LoadStep                       Test worker                    Step "ReadVerificationFailTest2" results:
    READ-20x1: n=(2/998); t[s]=(2.386/0.11893); size=(20KB); TP[op/s]=(0.83822/1.0); BW[MB/s]=(0.0081/0.0097); dur[us]=(59465/33086/85844); lat[us]=(21732/14089/29375)

The record pattern is:

<LOAD_TYPE>-<CONCURRENCY_LEVEL>x<DRIVER_COUNT>:
	n=(<COUNT_SUCCESS>/<COUNT_FAIL>);
	t[s]=(<ELAPSED_TIME>/<OPERATIONS_DURATION_SUM>)
	size=(<SIZE_TRANSFERRED>);
	TP[op/s]=(<RATE_MEAN>/(RATE_LAST));
	BW[MB/s]=(<BYTE_RATE_MEAN>/<BYTE_RATE_LAST>);
	dur[us]=(<DURATION_AVG>/<DURATION_MIN>/<DURATION_MAX>);
	lat[us]=(<LATENCY_AVG>/<LATENCY_MIN>/<LATENCY_MAX>);

• The equation (CONCURRENCY_LEVEL * DRIVER_COUNT * ELAPSED_TIME / OPERATIONS_DURATION_SUM) may be used as efficiency estimate

• Mean rates are calculated as current total count of items/bytes divided by current elapsed time.

• Last rates are calculated as exponentially decaying moving average where

  

  and "t" is the configured load-metrics-period parameter.

Note:

The metrics are differentiated by the load type so an user will see separate metrics for each load type used for a mixed load step.

Files

Test Step Specific Output Files

Effective Configuration Dump

File: effective-config.json

Messages

File: messages.log

3rd Party Log Messages

File: 3rdparty.log

Errors

File: errors.log

Different components of the application log the error messages into the errors.log file. Also, both storage drivers and load monitors log the failed I/O tasks with "ERR" log marker. A load monitor logs the results with the status different than "SUCCESS" with "DEBUG" level (not visible in the stdout, appears in the log file only). The load monitor's record format:

[endpoint: <STORAGE_NODE_ADDR>, ]
[client: <STORAGE_DRIVER_ADDR>, ]
item: <ITEM_NAME_OR_PATH>,
operation: <IO_TYPE>,
status: <IO_STATUS>

A storage drivers logs the results with the status different than "SUCCESS" with "WARN" level (appears both in the stdout and the log file).

Metrics

Note:

If test-step-metrics-precondition flag is set to true, the metrics are not persisted to a files (printed to the console only).

Periodic Snapshots

By default periodic current metrics dump occurs every 10 seconds and the metrics data is written to a CSV file metrics.csv

Field Name	Description
DateTimeISO8601	Timestamp in the ISO8601 format
TypeLoad	Load type (CREATE/READ/...)
Concurrency	The concurrency level
DriverCount	Count of the storage drivers used (may be more than 1 in the distributed mode)
CountSucc	Total successful I/O tasks count
CountFail	Total failed I/O tasks count
Size	Total transferred byte count
JobDuration[s]	Total step duration
DurationSum[s]	Total sum of the I/O tasks durations
TPAvg[op/s]	Total average throughput
TPLast[op/s]	Last final moving average throughput
BWAvg[MB/s]	Total average bandwidth
BWLast[MB/s]	Last final moving average bandwidth
DurationAvg[us]	Total average I/O tasks duration
DurationMin[us]	Minimum I/O task duration
DurationLoQ[us]	Low quartile of the I/O tasks duration distribution
DurationMed[us]	Median of the I/O tasks duration distribution
DurationHiQ[us]	High quartile of the I/O tasks duration distribution
DurationMax[us]	Maximum I/O task duration
LatencyAvg[us]	Total average I/O tasks latency
LatencyMin[us]	Minimum I/O task latency
LatencyLoQ[us]	Low quartile of the I/O tasks latency distribution
LatencyMed[us]	Median of the I/O tasks latency distribution
LatencyHiQ[us]	High quartile of the I/O tasks latency distribution
LatencyMax[us]	Maximum I/O task latency

Load Step Total Results

The total metrics accounted at the end of each load step and the results are written to a CSV file metrics.total.csv. The layout is the same as for periodic metrics snapshots

Intermediate

See [Intermediate Statistics Reporting](v3.4.0 Intermediate Statistics#reporting)

I/O Traces

The I/O trace records are generated for each I/O operation performed.

Note:

By default, the I/O trace logging is disabled. To enable the logging modify the config/logging.json file: change the log level threshold from "INFO" to "DEBUG" for the ioTraceFile logger (near the line #208)

Available Fields

Field Name	Description
StorageDriver	The address/hostname of the storage driver executed the operation
StorageNode	The target storage node address/hostname
ItemPath	The resulting item path
IoTypeCode	The I/O operation type code
StatusCode	The I/O operation resulting status code
ReqTimeStart	The I/O operation start timestamp in microseconds
Duration	The I/O operation total duration in microseconds
RespLatency	The I/O operation response latency in microseconds
DataLatency	The I/O operation response data latency ("1st byte" of the response content) in microseconds
TransferSize	The count of the bytes transferred within the I/O operation

IoTypeCode

Code	I/O Type
0	NOOP
1	CREATE
2	READ
3	UPDATE
4	DELETE

StatusCode

Code	Description	HTTP response codes
O	Pending (internal)
1	Active (internal)
2	Interrupted
3	Unknown failure	all other codes
4	Success	2xx
5	I/O Failure
6	Timeout	504
7	Unrecognized storage response
8	Client failure or invalid request	100, 400, 405, 409, 411, 414, 416
9	Internal storage failure	413, 415, 429, 500, 501, 502, 503, 505
10	Item not found on the storage	404
11	Authentication/access failure	401, 403
12	Data item corrupted	2xx
13	Not enough space on the storage	507

Items Lists

It's possible to configure the load step to save the items list into the file regardless of configured load type (Create/Read/etc). To do so an user should use item-output-file configuration parameter. CLI example:

java -jar <MONGOOSE_DIR>/mongoose.jar --item-output-file=items.csv ...

This is useful to perform a load over the items used earlier (in a different run). For example, to read the items created on the storage some time ago:

java -jar <MONGOOSE_DIR>/mongoose.jar --read --item-input-file=items.csv ...

Items List File Format

Items list file contains the CSV records each occupying a line. Each record contains comma-separated values which are:

1. Item Path
2. Data ring buffer offset (hexadecimal)
3. Size (decimal)
4. A pair of layer/mask values separated with "/" character