Learn how gprof can help you to identify the performance bottlenecks in your program’s source code
Code profiling is an important aspect of software development. It is
mostly done to identify those code snippets that consume more time than
expected, or to understand and trace the call flow of functions. This
not only aids in debugging many tricky problems, but also helps the
programmer to improve the software’s performance.
Although performance requirements vary from program to program, it’s
always advantageous to have minimum performance bottlenecks in the final
product. For example, a video player will usually have very strict
speed requirements while a calculator might not have the same kind of
requirements. Even so, a better-performing calculator will always be
preferred.
There are many tools available for code profiling in Linux, but one
of the popular tools is the GNU profiler – gprof. It is a free program
that comes as a part of GNU binary utils and is based on BSD gprof.
The sample code (sampleCode.c – on the disc) used in this guide is
written in the C programming language and compiled using GCC 4.7.3. All
the commands are executed on Bash 4.2.45 and the gprof version used is
2.23.2. The whole test environment is built on Ubuntu 13.04. Profile your code with gprof
Step 01 Compile profiling-enabled code
In order to profile a code, the first step is to enable profiling
while the code is being compiled and linked. In most cases, the command
line option -pg should enable profiling.
If compilation and linking commands are used separately, then this option is to be used in both cases. For example:
And if compilation and linking is being done in the same command then this option also needs to be added. For example:
gcc -Wall sampleCode.c -o sampleCode -pg
Step 02 Execute the binary – part 1
After the program is compiled (and linked) for profiling, the next
step is to execute it. One important point to remember is that the
program execution should happen in such a way that all the code blocks
(or at least the ones you want to profile) get executed. So make sure
that command-line arguments and inputs are given to the program
accordingly.
Here is how the profiling-enabled executable program ‘sampleCode’ was executed:
./sampleCode
Count = [1000000000]
So you can see that the program ‘sampleCode’ executed and exited normally. Step 03 Execute the binary – part 2
Once the program is executed, it produces a file named gmon.out.
ls gmon.out
gmon.out
This file contains the profiling data of the code blocks that were
actually hit during the program execution. It is not a regular text file
and therefore cannot be read normally. This can be confirmed by using
the file command in Linux.
file gmon.out
gmon.out: GNU prof performance data - version 1
Note 1: The file gmon.out is not produced if the program abnormally
terminates because of, say, an unhandled signal, by calling _exit()
function directly etc.
Note 2: This file gets created in the working directory of the
program at the time of its exit. So, make sure that the program has
required permissions for the same.
Note 3: A profiling-enabled program always produces a file named
gmon.out. So, make sure that an existing file with this name is not
overwritten. Step 04 Execute gprof
Once the profiling data (gmon.out) is available, the gprof tool can
be used to analyse and produce meaningful data from it. Here is the
general syntax of the gprof command :
So, the gprof command accepts the executable filename, profiling data
filename and the required command-line options to produce human-
readable profiling information which can be redirected to an output
file.
But, in the simplest form, the command-line tool gprof does not
require any argument (the arguments within [ ] are not mandatory). When
no argument is supplied, gprof looks for a.out as the default
executable-file-name and gmon.out as profiling-data-file-name in the
current directory, and the default output is produced on standard output
– stdout.
Let’s run gprof in our case :
gprof sampleCode gmon.out > prof_output
The command above redirects the output of gprof to a file named
prof_output. This file will now contain human-readable profiling
information in the form of a flat profile and call graph (more on these
later). Step 05 Annotated source
The annotated source listing gives an idea about the number of times
each line of the program was executed. To get the annotated source
listing …
First compile the source code with the -g option. This option enables debugging:
gcc -Wall -pg -g sampleCode.c -o sampleCode
Next, while running the gprof command, use the command-line option -A to produce the annotated source listing:
gprof -A sampleCode gmon.out > prof_ output
Step 06 Flat profile
The flat profile (see screen grab at top of page) shows
how much time your program spent in each function, and how many times
that function was called. If you simply want to know which functions
burn most of the cycles, it is stated concisely here.
The different columns in the Flat Profile table represent :
% time – The percentage of the total running time of the program used by this function.
cumulative seconds – A running sum of the number of seconds accounted for by this function and those listed above it.
self seconds – The number of seconds accounted for by this function alone. This is the major sort for this listing.
calls – The number of times this function was invoked (if this function is profiled, else blank).
self ms/call – The average number of milliseconds spent in this function per call (if this function is profiled, else blank).
total ms/call – The average number of milliseconds spent in this
function and its descendants per call (if this function is profiled,
else blank).
name – The name of the function. This is the minor sort for this
listing. The index shows the location of the function in the gprof
listing. If the index is in parentheses, it shows where it would appear
in the gprof listing if it were to be printed. Step 07 Call graph
The Call Graph (see screen below) shows, for each function, which
functions called it, which other functions it called, and how many
times. There is also an estimate of how much time was spent in the
subroutines of each function. This can suggest places where you might
try to eliminate function calls that use a lot of time.
Each entry in this table consists of several lines. The line with the
index number at the left- hand margin lists the current function. The
lines above it list the functions that called this function, and the
lines below it list the functions this one called. This line lists:
index – A unique number given to each element of the table. Index
numbers are sorted numerically. The index number is printed next to
every function name so it is easier to look up where the function is in
the table.
% time – This is the percentage of the ‘total’ time that was spent in
this function and its children. Note that due to different viewpoints,
functions excluded by options etc, these numbers will not add up to
100%.
self – This is the total amount of time spent in this function. For
the function’s parents, this is the amount of time that was propagated
directly from the function into this parent. For the function’s
children, this is the amount of time that was propagated directly from
the child into the function.
children – This is the total amount of time propagated into this function by its children.
For the function’s parents, it’s the amount of time that was
propagated from the function’s children into this parent. For the
function’s children, this is the amount of time that was propagated from
the child’s children to the function.
called – This is the number of times the
function was called. If the function called itself recursively, the
number only includes non- recursive calls and is followed by a ‘+’ and
the number of recursive calls.
For the function’s parents, this is the number of times this parent
called the function / the total number of times the function was called.
For the function’s children, this is the number of times the function
called this child / the total number of times the child was called
name – The name of the current function. The index number is printed
after it. If the function is a member of a cycle, the cycle number is
printed between the function’s name and the index number.
For the function’s parents, this is the name of the parent. For the function’s children, this is the name of the child. Step 08 Exclude a particular function
To exclude a particular function from the flat profile or call graph,
use the -P or -Q option respectively, along with the function name as
the argument.
For example, the following command would exclude the flat profile- and call graph-related details of func_a :
Step 09 Profile a particular function
To fetch the flat profile and call graph information of only a
particular function, use the -p and -q options respectively along with
the function name as the argument.
For example, the following command would produce the flat profile- and call graph-related details of func_a:
Step 10 Suppress verbose blurbs
By default, the gprof output contains detailed explanation of each
column of flat profile and call graph. This is good for beginners, but
you may want to suppress these details once you know everything. The
command-line option -b (or -brief) can be used for this purpose.
A chroot on Unix operating systems is an operation that
changes the apparent root directory for the current running process and
its children. A program that is run in such a modified environment
cannot name (and therefore normally not access) files outside the
designated directory tree. The term “chroot” may refer to the chroot(2) system call or the chroot(8) wrapper program. The modified environment is called a “chroot jail”. From Wikipedia.
Why it is required? If you want to set up your Linux box as a web
hosting server for its users, you may need to give SFTP access. But they
can get access to whole system Linux tree, just for reading but still
very unsecure. So it is mandatory to lock them in their home directory.
There are many other applications, it’s just a common example, so lets start its configuration.
Linux Box Detail:
Its mine Linux Box, your Linux system may vary. Only thing to take
care is the openssh-server version, because openssh-server-5.3p1 support
SFTP chroot. Older version supports but its tricky, please let me k now
if you want to know that too.
Operating System: CentOS 6.3/x86_64
Kernel Version: 2.6.32-279.19.1.el6/x86_64
Openssh Server Version: openssh-server-5.3p1-81.el6_3/x86_64
sshd Server Configuration:
Add the following tail output to your Linux box’s SSH
server configuration file /etc/ssh/sshd_config.
[rahulpanwar@myhost ~]# tail -6 /etc/ssh/sshd_config
#Subsystem sftp /usr/libexec/openssh/sftp-server
Subsystem sftp internal-sftp
Match Group www-hosting
ChrootDirectory %h
ForceCommand internal-sftp
AllowTcpForwarding no
Then restart sshd service to enable this configuration.
sshd[3505]: fatal: bad ownership or modes for chroot directory "/home/linuxexplore.com"
It’s ChrootDirectory ownership problem, sshd will reject sftp
connections to accounts that are set to chroot into any directory that
has ownership/permissions that sshd doesn’t consider secure. sshd’s
apparently strict ownership/permissions requirements dictate that every
directory in the chroot path must be owned by root and only writable for
the owner. So, for example, if the chroot environment is in a user’s
home directory both /home and /home/username must be owned by root and
have permissions like 755 or 750 ( group ownership should allow user to
access ).
If you are using sftp with public key check the following link: http://www.centos.org/modules/newbb/viewtopic.php?topic_id=37903&forum=59
If chroot environment is in user’s home directory, make sure user
have access to its home directory, or user would not be able to access
its publickey, produce the error given in above CentOS forum link.
The GNU Compiler Collection (GCC)
is easy to use, but it offers so many command-line options that no one
can remember them all. Here are five uncommon command-line options you
can use to get the most out of GCC.
To illustrate these examples, I used GCC 4.7.3 running on Ubuntu Linux 13.04 with Bash 4.2.45.
In the first stage, the preprocessor expands all the macros and header files, and strips off comments.
In the second stage, the compiler acts on the preprocessed code to produce assembly instructions.
In the third stage, the assembler converts the assembly instructions into machine-level code (object files).
In the final stage, the linker resolves all the unresolved symbols and combines all the object files to produce an executable.
When you compile a C/C++ source file using gcc, your final output is
an executable program. But in some situations you might want to know how
the preprocessor expanded a particular macro, or you might just want to
take a look at the assembly instructions. To see the intermediate
output produced after each of the compilation stages, use the -save-temps option.
For instance, suppose you compile the program helloworld.c using the -save-temps option:
Along with the final executable, gcc produces three other files.
helloworld.i is the output of the preprocessing stage, helloworld.s is
the output of the compilation stage, and helloworld.o is the output of
the assembly stage.
-Wextra
Many developers use the option -Wall to enable warnings during the compilation process, but -Wall does not report all possible warnings. It leaves out, for example, warnings about:
Missing parameter type
Comparison of a pointer with integer zero using >, <, >=, or <=.
Ambiguous virtual bases
If the compiler does not warn you about these problems, your program
might produce undesired results when you run it. Consider the following
code:
As you can see, the type of the argument "a" is not specified in
function func(). This could be a typo on the part of the programmer who,
for example, meant to declare "a" as a "long long" integer, but without
that declaration the compiler will assume the default type of variable
"a" as int. If you compile this code with the -Wall option,
gcc does not produce any warning, and the program could produce
undesired results. For example, if a "long long" value that is larger
than the maximum value that an "int" can hold is passed as an argument
to func(), the program will behave incorrectly.
If you compile the same code with the -Wextra option enabled, you should see the following output:
$ gcc -Wall -Wextra helloworld.c -o helloworld
helloworld.c: In function 'func':
helloworld.c:4:6: warning: type of 'a' defaults to 'int' [-Wmissing-parameter-type]
Once you know about this problem, you can easily fix it by explicitly mentioning the type of function argument "a." -Wextra offers similar warnings for pointer comparison problems. Consider the following code:
#include
void func()
{
int a = -1;
int *ptr = &a;
if(ptr >= 0)
{
a = a+1;
}
printf("\n a = [%d]\n",a);
return;
}
int main(void)
{
printf("\n HELLO \n");
func();
return 0;
}
The pointer "ptr" is being compared with the integer zero in the
function func(). This statement is useless, as ptr clearly contains the
address of the variable "a," which will always be a positive value. The
programmer must have missed the dereference operator * before ptr while
comparing its value with zero. Just as in the previous example, if you
compile this code with the -Wall option, gcc does not
produce any warning, but the program will produce wrong result (a=0) in
the output. On the other hand, when you use -Wextra, gcc reports:
$ gcc -Wall -Wextra helloworld.c -o helloworld
helloworld.c: In function 'func':
helloworld.c:9:12: warning: ordered comparison of pointer with integer zero [-Wextra]
As soon as you see a warning related to pointer comparison with zero,
you immediately know you have a typo in your code, which you can easily
fix by replacing (ptr>=0) with ((*ptr)>=0) in this case.
Read the gcc man page for other warnings -Wextra produces.
-Wfloat-equal
New programmers sometimes try to compare floating point variables
using the == operator – something you should never do because of the way floating point numbers are represented internally. The gcc compiler's -Wfloat-equal option produces a warning whenever it encounters a floating point comparison. Consider:
#include
void func(float a, float b)
{
printf("\n Inside func() \n");
if(a == b)
{
printf("\n a == b\n");
}
return;
}
int main(void)
{
printf("\n HELLO \n");
func(1.345, 1.345678);
return 0;
}
Here, the float arguments to the function func() are being compared
using the == operator. When you compile this code without using the -Wfloat-equal option, you'll see no warning, but with it, you should see output like this:
$ gcc -Wfloat-equal helloworld.c -o helloworld
helloworld.c: In function 'func':
helloworld.c:7:10: warning: comparing floating point with == or != is unsafe [-Wfloat-equal]
If you see that your code is directly comparing floats, you should
drop the direct comparison and think of better logic to solve the
problem.
-g
If you use the GNU debugger (GDB) to debug, or Valgrind to detect memory leaks in your program, always compile the program with the -g
option, which produces debugging information in the operating system's
native format. Other tools can use this information to produce detailed
output.
To see how it works, suppose the source file helloworld.c contains following code:
If you compile the code without the -g option and run Valgrind's memcheck tool, you'll see a problem – a memory leak:
$ valgrind --tool=memcheck --leak-check=yes ./helloworld
==3471== Memcheck, a memory error detector
==3471== Copyright (C) 2002-2012, and GNU GPL'd, by Julian Seward et al.
==3471== Using Valgrind-3.8.1 and LibVEX; rerun with -h for copyright info
==3471== Command: ./helloworld
==3471==
HELLO
Inside func()
==3471==
==3471== HEAP SUMMARY:
==3471== in use at exit: 10 bytes in 1 blocks
==3471== total heap usage: 1 allocs, 0 frees, 10 bytes allocated
==3471==
==3471== 10 bytes in 1 blocks are definitely lost in loss record 1 of 1
==3471== at 0x4C2CD7B: malloc (in /usr/lib/valgrind/vgpreload_memcheck-amd64-linux.so)
==3471== by 0x40058D: func (in /home/himanshu/practice/helloworld_dir/helloworld)
==3471== by 0x4005B6: main (in /home/himanshu/practice/helloworld_dir/helloworld)
==3471==
==3471== LEAK SUMMARY:
==3471== definitely lost: 10 bytes in 1 blocks
==3471== indirectly lost: 0 bytes in 0 blocks
==3471== possibly lost: 0 bytes in 0 blocks
==3471== still reachable: 0 bytes in 0 blocks
==3471== suppressed: 0 bytes in 0 blocks
==3471==
==3471== For counts of detected and suppressed errors, rerun with: -v
==3471== ERROR SUMMARY: 1 errors from 1 contexts (suppressed: 2 from 2)
The memcheck tool is able to detect the memory leak, but it is unable
to say where the leak actually takes place. Without that information,
you could have a big problem tracking down the leak when you're working
on projects that contain large source files.
If instead you compile the code with the -g option before you run memcheck, the tool can pinpoint the problem:
$ valgrind --tool=memcheck --leak-check=yes ./helloworld
==3517== Memcheck, a memory error detector
==3517== Copyright (C) 2002-2012, and GNU GPL'd, by Julian Seward et al.
==3517== Using Valgrind-3.8.1 and LibVEX; rerun with -h for copyright info
==3517== Command: ./helloworld
==3517==
HELLO
Inside func()
==3517==
==3517== HEAP SUMMARY:
==3517== in use at exit: 10 bytes in 1 blocks
==3517== total heap usage: 1 allocs, 0 frees, 10 bytes allocated
==3517==
==3517== 10 bytes in 1 blocks are definitely lost in loss record 1 of 1
==3517== at 0x4C2CD7B: malloc (in /usr/lib/valgrind/vgpreload_memcheck-amd64-linux.so)
==3517== by 0x40058D: func (helloworld.c:7)
==3517== by 0x4005B6: main (helloworld.c:16)
==3517==
==3517== LEAK SUMMARY:
==3517== definitely lost: 10 bytes in 1 blocks
==3517== indirectly lost: 0 bytes in 0 blocks
==3517== possibly lost: 0 bytes in 0 blocks
==3517== still reachable: 0 bytes in 0 blocks
==3517== suppressed: 0 bytes in 0 blocks
==3517==
==3517== For counts of detected and suppressed errors, rerun with: -v
==3517== ERROR SUMMARY: 1 errors from 1 contexts (suppressed: 2 from 2)
You might also want to profile your program. Code profiling can tell
you things such as how much time each function consumes, how many times a
function gets called, and which parts of your program are slow and need
improvement. In Linux, a popular code profiling tools is the GNU profiler, or gprof. This tool requires the code to be compiled (and linked) using gcc's -pg option. GNU gprof produces detailed profiling information in form of flat profile and call graph.
@file
All of these options may be useful, and you may want to use some or
all of them together for all of your compiles. If you find yourself
using many command-line options while compiling your programs, you can
put all the options in a file and pass the file name to gcc to use all
the flags in the file together. For instance, you could create a file
named options that contains the line -Wall -Wextra -Wfloat-equal, then pass the file name as a command-line option to gcc:
$ gcc @options helloworld.c -o helloworld
Keeping your gcc compiler options in an options file makes managing multiple command-line options easy.
