timings

  • reference
    +
    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.

    sync_write_commit_majority

    Time spent in replicating mutations to memory on a majority of the Data Service nodes that hold the data.

    sync_write_commit_majority_and_persist_on_master

    Time spent in replicating mutations to memory on a majority of the Data Service nodes that hold the data, plus time spent in writing mutations to disk on the node hosting the active vBucket for the data.

    sync_write_commit_persist_to_majority

    Time spent in replicating mutations to disk on a majority of the Data Service nodes that hold the data.

    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)