Use GNUprofiler to speed up Code Execution

Use GNUprofiler to speed up code running-Linux general technology-Linux programming and kernel information. For more information, see the following. Improving the performance of an application is a very time-consuming task, but it is not very obvious whether the functions in the program consume most of the execution time. In this article, we will learn how to use gprof for Linux ?? The user space and system calls on the platform accurately analyze performance bottlenecks.

Introduction

The performance requirements of various software may be very different, but it is not surprising that many applications have very strict performance requirements. A movie player is a good example: if a movie player can only play a movie at 75% of the required speed, it is almost useless.

If other applications (such as video encoding) are time-consuming operations, it is best to run the "batch processing" task. In this case, start a job and keep it running, then we can do other things. Although these types of applications do not have such hard performance indicators, increasing the speed will still bring many benefits. For example, you can encode more movies at a given time, encoding can be performed at a higher quality in the same time.

In general, in addition to the simplest application, the better the performance of other applications, the more useful this application is, the more popular it will become. For this reason, the performance consideration is (and should be) the first string in the head of many application developers.

Unfortunately, many attempts to make applications faster are in vain, because developers usually make small Optimizations to their own software, instead of studying how the program operates on a larger scale. For example, we may spend a lot of time to speed up a specific function to double the speed of the original, which is very good, however, if this function is rarely called (such as opening a file), reduce the execution time of this function from 200 ms to 100 ms, it does not have much impact on the overall execution time of the entire software.

The effective way to take advantage of your time is to optimize the frequently called part of the software as much as possible. For example, if the application spends 50% of its time on string processing functions, and these functions can be optimized to Improve the efficiency by 10%, the overall execution time of the application will be improved by 5%.

Therefore, if you want to optimize the program effectively, it is important to know exactly how time is spent in the application and the real input data. This behavior is called code profiling ). This article will briefly introduce a profiling tool provided by the GNU Compiler toolkit. Its name can be used to create an infinite illusion called GNU profiler (gprof ). This article is intended for beginners of open source software development tools.

Gprof is here to help

Before getting started with how to use gprof, You need to first understand where to proceed during the entire development cycle. Generally, there should be three goals for writing code, in order of importance:

Ensure that the software works correctly. This is usually the focus of the development process. Generally, if a software cannot even implement what we expect it to do, it makes no sense even if it runs very fast! Obviously, correctness may not be crucial in some cases; for example, if a movie player can correctly play a 99% movie file, it may occasionally show problems, it can still be used. But in general, correctness is much more important than speed.

The software is maintained. This is actually a subitem of the first target. Generally, if the software is poorly written, you (or someone else) can work very quickly even if it works well at the beginning) when fixing bugs or adding new features, the program's correctness may also be broken.

Allows the software to run quickly. This is the application of analysis. When the software runs correctly, we can start the profiling process to help it run faster.

Suppose we already have an application that can work. Next, let's take a look at how gprof can be used to precisely measure the time spent in application execution, the purpose of this operation is to find out where the optimization is best.

Gprof can be used to analyze C, C ++, Pascal, and Fortran 77 applications. The example in this article uses C.

Listing 1. Example of a time-consuming application



# Include

Int a (void ){
Int I = 0, g = 0;
While (I ++ <100000)
{
G + = I;
}
Return g;
}
Int B (void ){
Int I = 0, g = 0;
While (I ++ <400000)
{
G + = I;
}
Return g;
}

Int main (int argc, char ** argv)
{
Int iterations;

If (argc! = 2)
{
Printf ("Usage % s \ N ", argv [0]);
Exit (-1 );
}
Else
Iterations = atoi (argv [1]);

Printf ("No of iterations = % d \ n", iterations );

While (iterations --)
{
A ();
B ();
}
}



As we can see from the code, this very simple application contains two functions: a and B, both of which consume the CPU cycle in a busy cycle. The main function uses a loop to call these two functions repeatedly. The number of cycles of function B in the second function is four times that of function a. Therefore, we expect that after analyzing the code, we can see that about 20% of the time is spent in function, 80% of the time is spent in the B function. Next we will analyze the code and check whether our expectations are correct.

Enabling profiling is very simple. You only need to add-pg to the gcc compilation mark. The compilation method is as follows:

Gcc example1.c-pg-o example1-O2-lc

After compiling this application, you can run it in the normal way:

. /Example1 50000

After the program runs, you will see that a file gmon. out is created in the current directory.

Use output results

First, let's take a look at "flat profile". We can use the gprof command to obtain it. This requires passing the executable file and gmon. out file as parameters, as shown below:

Gprof example1 gmon. out-p

This will output the following content:

Listing 2. Results of flat profile



Flat profile:

Each sample counts as 0.01 seconds.
% Cumulative self total
Time seconds cils ms/call name
80.24 63.85 63.85 50000 1.28 B
20.26 79.97 16.12 50000 0.32 0.32



From this output, we can see that, as we expected, function B takes about four times the time spent by function. Real numbers are not very useful; they may not be very accurate due to rounding errors.

Smart readers may notice that many function calls (such as printf) do not appear in this output. This is because these functions are in the C Runtime Library (libc. so), (in this example) they are not compiled using-pg, so no analysis information is collected for the functions in this library. We will return to this issue later.

Next we want to know about "call graph", which can be obtained through the following method:

Gprof example1 gmon. out-q

This will output the following results.

Listing 3. Call graph



Call graph (explanation follows)
Granularity: each sample hit covers 2 byte (s) for 0.01% of 79.97 seconds

Index % time self children called name

[1] 100.0 0.00 79.97 main [1]
63.85 0.00 50000/50000 B [2]
16.12 0.00 50000/50000 a [3]
-----------------------------------------------
63.85 0.00 50000/50000 main [1]
[2] 79.8 63.85 0.00 50000 B [2]
-----------------------------------------------
16.12 0.00 50000/50000 main [1]
[3] 20.2 16.12 0.00 50000 a [3]
-----------------------------------------------



Finally, we may want to get a "annotated source code" list, which will output the source code to the application and add the comments of how many times each function is called.

To use this function, use the debug flag to compile the source code, so that the source code will be added to the executable program:

Gcc example1.c-g-pg-o example1-O2-lc

Run the application again as before:

. /Example1 50000

The gprof command should be:

Gprof example1 gmon. out-

This will output the following results:

Listing 4. Source Code with Annotation





* ** File/home/martynh/profarticle/example1.c:
# Include

50000-> int a (void ){
Int I = 0, g = 0;
While (I ++ <100000)
{
G + = I;
}
Return g;
}
50000-> int B (void ){
Int I = 0, g = 0;
While (I ++ <400000)
{
G + = I;
}
Return g;
}

Int main (int argc, char ** argv)
#####-> {
Int iterations;

If (argc! = 2)
{
Printf ("Usage % s \ N ", argv [0]);
Exit (-1 );
}
Else
Iterations = atoi (argv [1]);

Printf ("No of iterations = % d \ n", iterations );

While (iterations --)
{
A ();
B ();
}
}



Top 10 Lines:

Line Count

3 50000
11 50000
Execution Summary:

3 Executable lines in this file
3 Lines executed
100.00 Percent of the file executed

100000 Total number of line executions
33333.33 Average executions per line


Support for shared libraries

As previously mentioned, the support for code profiling is added by the compiler, so if you want to share the Library (including the C library libc. a) to obtain the profiling information, you need to use-pg to compile these libraries. Fortunately, many releases provide the C library version (libc_p.a) compiled with code profiling enabled ).

In my released gentoo, you need to add "profile" to the USE flag and re-Execute emerge glibc. after this process is completed, the/usr/lib/libc_p.a file has been created. For release versions that do not provide libc_p in accordance with the standard, you need to check whether it can be installed independently, or you may need to download the glibc source code and compile it yourself.

After obtaining the libc_p.a file, you can simply recompile the previous example. The method is as follows:

Gcc example1.c-g-pg-o example1-O2-lc_p

Then, you can run the application as before and get the flat profile or call graph. You should see a lot of C running functions, include printf (these functions are not very important in our test functions ).

User time and Kernel Time

Now we know how to use gprof. Next we can analyze the application simply and effectively, hoping to eliminate the performance bottleneck.

But now you may have noticed the biggest defect of gprof: it can only analyze the user time consumed by the application during running. Generally, it takes some time for an application to run user code and system code, such as kernel system calls.

If you make a slight modification to listing 1, you can clearly see this problem:

Listing 5. Add the system call analysis function for Listing 1



# Include

Int a (void ){
Sleep (1 );
Return 0;
}
Int B (void ){
Sleep (4 );
Return 0;
}

Int main (int argc, char ** argv)
{
Int iterations;

If (argc! = 2)
{
Printf ("Usage % s \ N ", argv [0]);
Exit (-1 );
}
Else
Iterations = atoi (argv [1]);

Printf ("No of iterations = % d \ n", iterations );

While (iterations --)
{
A ();
B ();
}
}



As you can see, we have modified the code in Listing 1. Now function a and function B no longer only process busy loops, instead, call the sleep function of C runtime to suspend execution for 1 second and 4 second respectively.

Compile this application as before:

Gcc example2.c-g-pg-o example2-O2-lc_p

And let the program loop for 30 times:

. /Example2 30

The generated flat profile is as follows:

Listing 6. flat profile displays the system call results



Flat profile:

Each sample counts as 0.01 seconds.
No time accumulated

% Cumulative self total
Time seconds CILS Ts/call name
0.00 0.00 0.00 120 0.00 sigprocmask
0.00 0.00 0.00 61 0.00 _ libc_sigaction
0.00 0.00 0.00 61 0.00 0.00 sigaction
0.00 0.00 0.00 60 0.00 0.00 nanosleep
0.00 0.00 0.00 60 0.00 0.00 sleep
0.00 0.00 0.00 30 0.00 0.00
0.00 0.00 0.00 30 0.00 0.00 B
0.00 0.00 0.00 21 0.00 _ IO_file_overflow
0.00 0.00 0.00 3 0.00 _ IO_new_file_xsputn
0.00 0.00 0.00 2 0.00 _ IO_new_do_write
0.00 0.00 0.00 2 0.00 _ find_specmb
0.00 0.00 0.00 2 0.00 _ guard_setup
0.00 0.00 0.00 1 0.00 _ IO_default_xsputn
0.00 0.00 0.00 1 0.00 _ IO_doallocbuf
0.00 0.00 0.00 1 0.00 _ IO_file_doallocate
0.00 0.00 0.00 1 0.00 _ IO_file_stat
0.00 0.00 0.00 1 0.00 _ IO_file_write
0.00 0.00 0.00 1 0.00 _ IO_setb
0.00 0.00 0.00 1 0.00 0.00 ____ strtol_internal
0.00 0.00 0.00 1 0.00 ___ fxstat64
0.00 0.00 0.00 1 0.00 _ cxa_atexit
0.00 0.00 0.00 1 0.00 _ errno_location
0.00 0.00 0.00 1 0.00 _ new_exitfn
0.00 0.00 0.00 1 0.00 _ strtol_internal
0.00 0.00 0.00 1 0.00 _ itoa_word
0.00 0.00 0.00 1 0.00 _ mcleanup
0.00 0.00 0.00 1 0.00 0.00 atexit
0.00 0.00 0.00 1 0.00 0.00 atoi
0.00 0.00 0.00 1 0.00 0.00 exit
0.00 0.00 0.00 1 0.00 0.00 flockfile
0.00 0.00 0.00 1 0.00 0.00 funlockfile
0.00 0.00 0.00 1 0.00 0.00 main
0.00 0.00 0.00 1 0.00 0.00 mmap
0.00 0.00 0.00 1 0.00 0.00 moncontrol
0.00 0.00 0.00 1 0.00 0.00 new_do_write
0.00 0.00 0.00 1 0.00 0.00 printf
0.00 0.00 0.00 1 0.00 0.00 setitimer
0.00 0.00 0.00 1 0.00 0.00 vfprintf
0.00 0.00 0.00 1 0.00 0.00 write



If the output result is analyzed, we can see that although profiler has recorded the exact number of calls to each function, the time recorded for these functions (actually all functions) all are 0. 00. this is because the sleep function actually executes a call to the kernel space, thus suspending the execution of the application, and then effectively pausing the execution, and waiting for the kernel to wake up again. Since the time spent on user space execution is much smaller than the time spent on Kernel sleep, it is rounded to zero. The reason is that gprof only works by sampling and measuring the running time at a fixed period. Therefore, when the program is not running, the program will not be sampled and measured.

This is actually a double-edged sword. In one aspect, this makes some programs very difficult to optimize, such as programs that spend most of their time in kernel space, or because of external factors (such as operating system I/O subsystem overload) the program runs very slowly. On the other hand, this means that profiling is not affected by other events in the system (for example, another user uses a lot of CPU time ).

Generally, there is a good benchmark test that can be used to view how useful gprof is to help optimize the application by executing it under the time command. This command shows how much time is required for an application to run, and how much time it takes in the user space and kernel space.

If you look at the example in Listing 2:

Time./example2 30

The output result is as follows:

Listing 7. output result of the time Command



No of iterations = 30

Real 2m30. 295 s
User 0m0. 000 s
Sys 0m0. 004 s



We can see that there is almost no time spent on Executing User space code, so gprof is not very useful here.

Conclusion

Despite the above restrictions, gprof is still a very useful tool for code optimization. If most of your code is user-space-intensive, it is more useful. It is a good idea to use time to run the program and determine whether gprof can generate useful information.

If gprof is not suitable for your profiling needs, there are other tools to overcome some gprof defects, including OProfile and Sysprof (see references for links to these tools ).

On the other hand, assuming that gcc has been installed and gprof is a major advantage over other tools, it is likely that the required tools have already been installed on Linux machines.

About the author

Martyn Honeyford graduated from the University of Nottingham in 1996 and obtained a bachelor's degree in computer science. Since then, he has become a software engineer at the ibm uk lab in Hursley, England. He is currently a developer in the WebSphere MQ Everyplace development team. When he is not at work, he often plays electric guitar (which is very bad) or crazy video games. You can contact Martyn through a martynh@uk.ibm.com.