Skip to content

perf_dump

Jump to bottom
Matthew Von-Maszewski edited this page Sep 29, 2016 · 22 revisions

Summary

The perf_dump utility was released with leveldb in Riak 1.3. The utility accesses a shared memory segment created by Basho's leveldb. This shared memory segment is not part of Google's original leveldb implementation. perf_dump reads performance counters contained within the shared memory segment and outputs their current values to the console.

Note: the counters represent server level statistics, not database / vnode statistics.

IMPORTANT: Enabling perf counters

A change to perf_counters occurred on June 15, 2015. There is now a switch to enable or disable the performance counters. The default is disabled. Performance counters must be enabled by creating an empty file /etc/riak/perf_counters. Here are example commands executed as root user:

   mkdir /etc/riak
   touch /etc/riak/perf_counters

Building perf_dump

You must have Riak's leveldb source code. The source code is available via the github.com basho/leveldb repository (if not already included in your Riak installation).

In the leveldb subdirectory, execute "make perf_dump" (no quotes). This will build perf_dump and leave the executable in the leveldb subdirectory.

Executing perf_dump

Riak must have executed once, or be executing at the time when using perf_dump. More specifically, Riak's leveldb must have create the shared memory segment before first using perf_dump.

Simply type "./perf_dump" at your unix/linux command prompt. You should receive a series of "name: value" lines ... or an error message suggesting an execution problem.

About the shared memory segment

  • The shared memory segment is created whenever Riak's leveldb executes and the segment does not already exist.
  • leveldb never destroys the shared memory segment or resets the counters. This characteristic was chosen to facilitate snmp implementations.
  • under Linux, the shared memory segment is visible via "ipcs" command
  • under Linux, the shared memory segment can be removed (hence reset) via the "ipcrm -m <value from ipcs>"

Accessing perf counters from leveldb api

The performance counters available via perf_dump are also available through the leveldb::DB::GetProperty() api call. Prepend the string "leveldb." to each counter name below in your request.

Example output (as of Riak 1.3, June 2013)

~$ perf_dump
1371580247835537, 0, ROFileOpen, 0
1371580247835537, 0, ROFileClose, 0
1371580247835537, 0, ROFileUnmap, 0
1371580247835537, 0, RWFileOpen, 362083
1371580247835537, 0, RWFileClose, 361980
1371580247835537, 0, RWFileUnmap, 1041776
1371580247835537, 0, ApiOpen, 275
1371580247835537, 0, ApiGet, 1430125182
1371580247835537, 0, ApiWrite, 1244537602
1371580247835537, 0, WriteSleep, 32412896
1371580247835537, 0, WriteWaitImm, 0
1371580247835537, 0, WriteWaitLevel0, 0
1371580247835537, 0, WriteNewMem, 53591
1371580247835537, 0, WriteError, 0
1371580247835537, 0, WriteNoWait, 1244537602
1371580247835537, 0, GetMem, 160340
1371580247835537, 0, GetImm, 175
1371580247835537, 0, GetVersion, 1429964667
1371580247835537, 0, SearchLevel[0], 1230955041
1371580247835537, 0, SearchLevel[1], 1223462270
1371580247835537, 0, SearchLevel[2], 1097980076
1371580247835537, 0, SearchLevel[3], 913155824
1371580247835537, 0, SearchLevel[4], 368557553
1371580247835537, 0, SearchLevel[5], 0
1371580247835537, 0, SearchLevel[6], 0
1371580247835537, 0, TableCached, 7339872099
1371580247835537, 0, TableOpened, 24383877
1371580247835537, 0, TableGet, 0
1371580247835537, 0, BGCloseUnmap, 1041776
1371580247835537, 0, BGCompactImm, 36382
1371580247835537, 0, BGNormal, 44506
1371580247835537, 0, BGCompactLevel0, 10892
1371580247835537, 0, BlockFiltered, 6830858919
1371580247835537, 0, BlockFilterFalse, 3099036
1371580247835537, 0, BlockCached, 157926997
1371580247835537, 0, BlockRead, 6448028987
1371580247835537, 0, BlockFilterRead, 24350138
1371580247835537, 0, BlockValidGet, 0
1371580247835537, 0, Debug[0], 0
1371580247835537, 0, Debug[1], 0
1371580247835537, 0, Debug[2], 0
1371580247835537, 0, Debug[3], 0
1371580247835537, 0, Debug[4], 0
1371580247835537, 0, ReadBlockError, 0
1371580247835537, 0, DBIterNew, 21306
1371580247835537, 0, DBIterNext, 191975551
1371580247835537, 0, DBIterPrev, 0
1371580247835537, 0, DBIterSeek, 30
1371580247835537, 0, DBIterSeekFirst, 136
1371580247835537, 0, DBIterSeekLast, 0
1371580247835537, 0, DBIterDelete, 21282
1371580247835537, 0, eleveldbDirect, 2866659842
1371580247835537, 0, eleveldbQueued, 0
1371580247835537, 0, eleveldbDequeued, 0
1371580247835537, 0, elevelRefCreate, 2865372732
1371580247835537, 0, elevelRefDelete, 2865372638
1371580247835537, 0, ThrottleGauge, 91
1371580247835537, 0, ThrottleCounter, 143104320
1371580247835537, 0, ThrottleMicros0, 267896539008
1371580247835537, 0, ThrottleKeys0, 46735995709
1371580247835537, 0, ThrottleBacklog0, 44492
1371580247835537, 0, ThrottleCompacts0, 10891
1371580247835537, 0, ThrottleMicros1, 1229627984510
1371580247835537, 0, ThrottleKeys1, 14766555057
1371580247835537, 0, ThrottleBacklog1, 113801
1371580247835537, 0, ThrottleCompacts1, 41376
  • column one is microseconds from a gettimeofday() call.
  • column two is the number of seconds elapsed since prior dump if using -d option
  • column three is name of the performance counter
  • column four is the value of the performance counter

All counters except ThrottleGauge increment over time. Debug counters can change between releases per programmer whim (do not rely on those counters ... ever).

Notes on counters (as of Riak 1.3, June 2013)

These counters were added over time to help debug leveldb performance issues. They are not arranged in any particular order. Therefore this section attempts to group and detail some of the more useful counters.

API calls

These counters track basic leveldb API calls:

Name Notes
ApiOpen call made to open a database (success/failure unknown)
ApiGet retrieve a specific key
ApiWrite write a specific key or write batch

These counters track API calls / actions related to iterators:

Name Notes
DBIterNew request for an iterator object
DBIterSeekFirst iterator object's SeekFirst call
DBIterSeekLast iterator object's SeekLast call
DBIterSeek iterator object's Seek call
DBIterPrev iterator object's Prev call
DBIterNext iterator object's Next call
DBIterClose iterator object released

file cache (size controlled by Options::max_open_files)

Name Notes
TableCached leveldb table file found in file cache
TableOpened leveldb table file must be opened before data read (expensive!)

block cache

Name Notes
BlockCached block containing key/value found in block cache
BlockRead block *potentially* containing key/value read from disk

bloom filter

Name Notes
BlockFiltered read of target block averted by bloom filter miss (key not in block/table)
BlockFilterFalse bloom filter indicated key likely exists, but actual block did not contain key (false positive)

Critical Read Errors

Name Notes
ReadBlockError a data block read failed or data did not pass CRC / compression hash checks *serious issue*
Clone this wiki locally