timings

timings

Provides timing statistics.

Syntax

Request syntax:

cbstats host:11210 [common options] timings

Description

The timing stats provide histogram data from high-resolution timers over various operations within the system. This only measures the time spent in the front-end thread for each operation, meaning that the timings may not be representative if items have to be fetched from disk as part of the operation.

To retrieve more accurate timing statistics, use mctimings instead of timings.

The following are the possible return values, which depend on what occurred on the data bucket:

Table 1. Return values
Values Description
bg_load Background fetches waiting for disk.
bg_wait Background fetches waiting in the dispatcher queue.
set_with_meta set_with_meta latencies.
access_scanner Access scanner run times.
checkpoint_remover Checkpoint remover run times.
item_pager Item pager run times.
expiry_pager Expiry pager run times.
pending_ops Client connections blocked for operations in pending vBuckets.
data_age Age of data written to disk.
disk_commit Time waiting for a commit after a batch of updates.
disk_del Wait for disk to delete an item.
disk_vb_del Waiting for disk to delete a vBucket.
disk_insert Wait for disk to store a new item.
disk_update Wait time for disk to modify an existing item.
get_cmd Servicing get requests.
store_cmd Servicing store requests.
arith_cmd Servicing incr/decr requests.
get_stats_cmd Servicing get_stats requests.
get_vb_cmd Servicing vBucket status requests.
set_vb_cmd Servicing vBucket set state commands.
del_vb_cmd Servicing vBucket deletion commands.
chk_persistence_cmd Waiting for checkpoint persistence.
item_alloc_sizes Item allocation size counters (in bytes).
notify_io Time for waking blocked connections.
paged_out_time Time (in seconds) objects are non-resident.
storage_age Time since most recently persisted item was initially queued for storage.
bg_batch_size Batch size for background fetches.
persistence_cursor_get_all_items Time spent in fetching all items by persistence cursor from checkpoint queues.
dcp_cursors_get_all_items Time spent in fetching all items by all dcp cursors from checkpoint queues.
Note: The most useful stats for understanding get and set timings are get_cmd and store_cmd.

Options

There are no options for this command. For common cbstats options, see cbstats.

Example

Request

cbstats localhost:11210 -u Administrator -p password -b beer-sample timings

Response

 checkpoint_remover (101 total)
    2ms - 4ms        : ( 12.87%) 13 █████▌
    4ms - 8ms        : ( 94.06%) 82 ██████████████████████████████████▉
    8ms - 16ms       : ( 98.02%)  4 █▋
    16ms - 32ms      : (100.00%)  2 ▊
    Avg              : (    4ms)
 dcp_cursors_get_all_items (2 total)
    1us - 2us        : ( 50.00%) 1 ██████████████████████ 
    2us - 4us        : ( 50.00%) 0  
    4us - 8us        : (100.00%) 1 ██████████████████████ 
    Avg              : (    2us)
 disk_commit (1 total)
    2ms - 4ms        : (100.00%) 1 ████████████████████████████████████████████ 
    Avg              : (    2ms)
 disk_update (1 total)
    4us - 8us        : (100.00%) 1 ████████████████████████████████████████████ 
    Avg              : (    4us)
 get_cmd (3 total)
    4m:28s - 8m:56s  : (100.00%) 3 ████████████████████████████████████████████ 
    Avg              : ( 4m:28s)
 get_stats_cmd (2220 total)
    16s - 33s        : (  0.50%)   11 ▏
    33s - 1m:07s     : (  4.50%)   89 █▋
    1m:07s - 2m:14s  : ( 14.05%)  212 ███▉
    2m:14s - 4m:28s  : ( 42.12%)  623 ███████████▌
    4m:28s - 8m:56s  : (100.00%) 1285 ███████████████████████▋
    Avg              : ( 3m:20s)
 item_alloc_sizes (1 total)
    512 - 1KB     : (100.00%) 1 ███████████████████████████████████████████████ 
    Avg           : (    512)
 notify_io (4839 total)
    0 - 1us          : ( 17.42%)  843 ███████▏
    1us - 2us        : ( 26.04%)  417 ███▌
    2us - 4us        : ( 42.10%)  777 ██████▌
    4us - 8us        : ( 70.04%) 1352 ███████████▍
    8us - 16us       : ( 78.43%)  406 ███▍
    16us - 32us      : ( 90.80%)  599 █████ 
    32us - 64us      : ( 95.60%)  232 █▉
    64us - 128us     : ( 96.42%)   40 ▎
    128us - 256us    : ( 97.56%)   55 ▍
    256us - 512us    : ( 98.74%)   57 ▍
    512us - 1ms      : ( 99.03%)   14  
    1ms - 2ms        : ( 99.24%)   10  
    2ms - 4ms        : ( 99.48%)   12  
    4ms - 8ms        : ( 99.90%)   20 ▏
    8ms - 16ms       : ( 99.98%)    4  
    16ms - 32ms      : (100.00%)    1  
    Avg              : (   46us)
 persistence_cursor_get_all_items (60416 total)
    0 - 1us          : ( 96.83%) 58501 ██████████████████████████████████████▋
    1us - 2us        : ( 99.33%)  1511 █ 
    2us - 4us        : ( 99.79%)   276 ▏
    4us - 8us        : ( 99.82%)    18  
    8us - 16us       : ( 99.83%)     8  
    16us - 32us      : ( 99.85%)    11  
    32us - 64us      : ( 99.90%)    32  
    64us - 128us     : ( 99.94%)    24  
    128us - 256us    : ( 99.95%)     5  
    256us - 512us    : ( 99.96%)     4  
    512us - 1ms      : ( 99.96%)     1  
    1ms - 2ms        : ( 99.97%)     4  
    2ms - 4ms        : ( 99.98%)     7  
    4ms - 8ms        : ( 99.99%)     7  
    8ms - 16ms       : (100.00%)     6  
    16ms - 32ms      : (100.00%)     1  
    Avg              : (    1us)
 storage_age (1 total)
    0 - 1us          : (100.00%) 1 ████████████████████████████████████████████ 
    Avg              : (      0)
 store_cmd (1 total)
    4m:28s - 8m:56s  : (100.00%) 1 ████████████████████████████████████████████ 
    Avg              : ( 4m:28s)