Profiling

Guidelines when profiling:

  • Define clearly what to profile.
  • Find a load that represents what to profile. This is often the hardest part, as there is a lot of noise if stressing other components.
  • Make sure that there are no other bottlenecks that blocks stressing the profiled component. It makes little sense to do cpu profiling if the network is the limitation.
  • If possible, write special unit-tests like benchmark programs that stress exactly what to profile.
  • If the system is multithreaded:
    • Always profile single threaded first - that gives a baseline for doing the scaling tests. Verify one is utilizing as many cores as expected.
    • Increase scaling gradually to at least 2x numcores or until throughput degrades.

Also see Using valgrind with Vespa.

CPU profiling

vmstat

vmstat can be used to figure out what kind of resources are used:

  • cpu usage split in user, system, idle, and io wait: system should be low(<10)
  • swap in/out: should be zero.
Note: A maxed out system should have either maxed out disks or cpu (idle == 0). If not, there might be locks.

Example:

$ vmstat 1

procs -----------memory---------- ---swap-- -----io---- --system-- ----cpu----
r  b   swpd   free   buff  cache   si   so    bi    bo   in    cs us sy id wa
0  0   5628 3315460 304024 23008616    0    0    14    34    0     0  0  0 99  0
1  0   5628 3298884 304024 23008640    0    0     0   396   33  4615  9  1 90  0
0  0   5628 3316336 304028 23008644    0    0     0     0   15  4469  4  1 95  0
0  0   5628 3316592 304028 23008644    0    0     0     0   24  4364  0  0 100  0
0  0   5628 3316592 304028 23008644    0    0     0  2948   20  4305  0  0 100  0
0  0   5628 3316468 304028 23008644    0    0     0     0   22  4259  0  0 100  0
0  0   5628 3316468 304028 23008644    0    0     0   180   20  4279  0  0 100  0
0  0   5628 3316468 304028 23008644    0    0     0     0   26  4349  0  0 100  0
16  0   5628 3284236 304056 23008688    0    0    12   188   17  9196 38  2 60  0
19  0   5628 3267020 304056 23008732    0    0     8   128   44  6408 99  1  0  0
16  0   5628 3245472 304060 23008840    0    0    20     0    9  7191 99  1  0  0
17  0   5628 3227784 304060 23008872    0    0    20     0   27  6420 99  1  0  0
top Use top to see which applications consume cpu and memory.

OProfile

This section explains how to setup OProfile and doing simple profiling. See the OProfile manual for examples of more complicated OProfile usage. OProfile is the best tool to find where the system is spending time. It gives an accurate view at a cost of 0.1-2%. Use a real host - it will not work on OpenVZ jails or linux containers.

Install

This will also install bindings that allow profiling java applications as well:

$ sudo yum install oprofile oprofile-jit

Set up

It is useful to have kernel debug info installed to get symbol info for the Linux kernel:

$ sudo yum install kernel-debuginfo
Its important to get somewhat same version of kernel-debuginfo as the kernel package. Then setup OProfile to point to the kernel debuginfo file and ensure that one get per-application profiles:
$ sudo opcontrol --separate=kernel --vmlinux=$(rpm -ql kernel-debuginfo | grep vmlinux)
OProfile is typically run like:
$ sudo opcontrol --start
$ sudo opcontrol --reset
$ # put some load on the system
$ sudo opcontrol --shutdown

Profile java applications

To profile java applications, start the java application with -agentlib:jvmti_oprofile. For Vespa, set jvmargs or set the services.agentlib variable to jvmti_oprofile - refer to setting vespa variables. jvmti_oprofile is installed when installing oprofile-jit with yum. Then restart services.

Troubleshooting

If there is no output from opreport -l, it is probably because the kernel is to old for the CPU. OProfile will not be able to do to event profiling. To fix, force OProfile to use the timer mode:

$ sudo opcontrol --shutdown
$ sudo opcontrol --deinit
$ sudo modprobe oprofile timer=1

Analysis

$ opreport -l # gives whole system - all one needs to know.
$ opreport -l "path of binary" #  i.e. "*vespa-proton-bin" -> gives a view of the binary only.

For java applications, its important to let the application run for a while to allow the JIT compiler to do its magic. Then run opcontrol --dump before inspecting OProfile reports.