Profiling adalah aspek penting dari pemrograman perangkat lunak. Melalui pembuatan profil seseorang dapat menentukan bagian-bagian dalam kode program yang memakan waktu dan perlu ditulis ulang. Ini membantu membuat eksekusi program Anda lebih cepat yang selalu diinginkan.
Dalam proyek yang sangat besar, pembuatan profil dapat menghemat hari Anda dengan tidak hanya menentukan bagian dalam program Anda yang lebih lambat dalam eksekusi dari yang diharapkan, tetapi juga dapat membantu Anda menemukan banyak statistik lain di mana banyak bug potensial dapat ditemukan dan diselesaikan.
Dalam artikel ini, kita akan menjelajahi alat profil GNU ‘gprof’.
Cara menggunakan gprof
Menggunakan alat gprof sama sekali tidak rumit. Anda hanya perlu melakukan hal berikut pada level tinggi:
- Aktifkan pembuatan profil saat mengkompilasi kode
- Jalankan kode program untuk menghasilkan data profil
- Jalankan alat gprof pada file data profil (dibuat pada langkah di atas).
Langkah terakhir di atas menghasilkan file analisis yang dalam bentuk yang dapat dibaca manusia. File ini berisi beberapa tabel (profil datar dan grafik panggilan) di samping beberapa informasi lainnya. Sementara profil datar memberikan gambaran tentang informasi waktu fungsi seperti konsumsi waktu untuk pelaksanaan fungsi tertentu, berapa kali dipanggil, dll. Di sisi lain, grafik panggilan berfokus pada setiap fungsi seperti fungsi yang melaluinya fungsi dipanggil, apa semua fungsi dipanggil dari dalam fungsi khusus ini dll. Jadi dengan cara ini orang bisa mendapatkan ide tentang waktu eksekusi yang dihabiskan di sub-rutin juga.
Mari kita coba dan pahami tiga langkah yang tercantum di atas melalui contoh praktis. Kode tes berikut akan digunakan di seluruh artikel :
//test_gprof.c
#include<stdio.h>
void new_func1(void);
void func1(void)
{
printf("\n Inside func1 \n");
int i = 0;
for(;i<0xffffffff;i++);
new_func1();
return;
}
static void func2(void)
{
printf("\n Inside func2 \n");
int i = 0;
for(;i<0xffffffaa;i++);
return;
}
int main(void)
{
printf("\n Inside main()\n");
int i = 0;
for(;i<0xffffff;i++);
func1();
func2();
return 0;
} //test_gprof_new.c
#include<stdio.h>
void new_func1(void)
{
printf("\n Inside new_func1()\n");
int i = 0;
for(;i<0xffffffee;i++);
return;
} Perhatikan bahwa loop 'for' di dalam fungsi ada untuk menghabiskan beberapa waktu eksekusi.
Langkah-1 :Pembuatan profil diaktifkan saat kompilasi
Pada langkah pertama ini, kita perlu memastikan bahwa pembuatan profil diaktifkan saat kompilasi kode selesai. Ini dimungkinkan dengan menambahkan opsi '-pg' pada langkah kompilasi.
Dari halaman manual gcc :
-pg :Menghasilkan kode tambahan untuk menulis informasi profil yang cocok untuk program analisis gprof. Anda harus menggunakan opsi ini saat mengompilasi file sumber yang Anda inginkan datanya, dan Anda juga harus menggunakannya saat menautkan.
Jadi, mari kita kompilasi kode kita dengan opsi ‘-pg’ :
$ gcc -Wall -pg test_gprof.c test_gprof_new.c -o test_gprof $
Harap dicatat:Opsi '-pg' dapat digunakan dengan perintah gcc yang mengkompilasi (opsi -c), perintah gcc yang menautkan (opsi -o pada file objek) dan dengan perintah gcc yang melakukan keduanya (seperti pada contoh di atas) .
Langkah-2 :Jalankan kodenya
Pada langkah kedua, file biner yang dihasilkan sebagai hasil dari langkah-1 (di atas) dieksekusi sehingga informasi profil dapat dihasilkan.
$ ls test_gprof test_gprof.c test_gprof_new.c $ ./test_gprof Inside main() Inside func1 Inside new_func1() Inside func2 $ ls gmon.out test_gprof test_gprof.c test_gprof_new.c $
Jadi kita melihat bahwa ketika biner dieksekusi, file baru 'gmon.out' dihasilkan di direktori kerja saat ini.
Perhatikan bahwa saat eksekusi jika program mengubah direktori kerja saat ini (menggunakan chdir) maka gmon.out akan diproduksi di direktori kerja baru saat ini. Selain itu, program Anda harus memiliki izin yang memadai agar gmon.out dapat dibuat di direktori kerja saat ini.
Langkah-3 :Jalankan alat gprof
Pada langkah ini, alat gprof dijalankan dengan nama yang dapat dieksekusi dan 'gmon.out' yang dihasilkan di atas sebagai argumen. Ini menghasilkan file analisis yang berisi semua informasi profil yang diinginkan.
$ gprof test_gprof gmon.out > analysis.txt
Perhatikan bahwa seseorang dapat secara eksplisit menentukan file output (seperti pada contoh di atas) atau informasi dihasilkan di stdout.
$ ls analysis.txt gmon.out test_gprof test_gprof.c test_gprof_new.c
Jadi kita melihat bahwa file bernama 'analysis.txt' telah dibuat.
Pada catatan terkait, Anda juga harus memahami cara men-debug program C Anda menggunakan gdb.
Memahami informasi pembuatan profil
Seperti yang dihasilkan di atas, semua informasi profil sekarang hadir di 'analysis.txt'. Mari kita lihat file teks ini :
Flat profile:
Each sample counts as 0.01 seconds.
% cumulative self self total
time seconds seconds calls s/call s/call name
33.86 15.52 15.52 1 15.52 15.52 func2
33.82 31.02 15.50 1 15.50 15.50 new_func1
33.29 46.27 15.26 1 15.26 30.75 func1
0.07 46.30 0.03 main
% the percentage of the total running time of the
time program used by this function.
cumulative a running sum of the number of seconds accounted
seconds for by this function and those listed above it.
self the number of seconds accounted for by this
seconds 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 the average number of milliseconds spent in this
ms/call function per call, if this function is profiled,
else blank.
total the average number of milliseconds spent in this
ms/call function and its descendents 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 parenthesis it shows where it would appear in
the gprof listing if it were to be printed.
Call graph (explanation follows)
granularity: each sample hit covers 2 byte(s) for 0.02% of 46.30 seconds
index % time self children called name
[1] 100.0 0.03 46.27 main [1]
15.26 15.50 1/1 func1 [2]
15.52 0.00 1/1 func2 [3]
-----------------------------------------------
15.26 15.50 1/1 main [1]
[2] 66.4 15.26 15.50 1 func1 [2]
15.50 0.00 1/1 new_func1 [4]
-----------------------------------------------
15.52 0.00 1/1 main [1]
[3] 33.5 15.52 0.00 1 func2 [3]
-----------------------------------------------
15.50 0.00 1/1 func1 [2]
[4] 33.5 15.50 0.00 1 new_func1 [4]
-----------------------------------------------
This table describes the call tree of the program, and was sorted by
the total amount of time spent in each function and its children.
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 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.
children This is the total amount of time propagated into this
function by its children.
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.
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, the fields have the following meanings:
self This is the amount of time that was propagated directly
from the function into this parent.
children This is the amount of time that was propagated from
the function's children into this parent.
called This is the number of times this parent called the
function `/' the total number of times the function
was called. Recursive calls to the function are not
included in the number after the `/'.
name This is the name of the parent. The parent's index
number is printed after it. If the parent is a
member of a cycle, the cycle number is printed between
the name and the index number.
If the parents of the function cannot be determined, the word
`' is printed in the `name' field, and all the other
fields are blank.
For the function's children, the fields have the following meanings:
self This is the amount of time that was propagated directly
from the child into the function.
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 called
this child `/' the total number of times the child
was called. Recursive calls by the child are not
listed in the number after the `/'.
name This is the name of the child. The child's index
number is printed after it. If the child is a
member of a cycle, the cycle number is printed
between the name and the index number.
If there are any cycles (circles) in the call graph, there is an
entry for the cycle-as-a-whole. This entry shows who called the
cycle (as parents) and the members of the cycle (as children.)
The `+' recursive calls entry shows the number of function calls that
were internal to the cycle, and the calls entry for each member shows,
for that member, how many times it was called from other members of
the cycle.
Index by function name
[2] func1 [1] main
[3] func2 [4] new_func1 Jadi (seperti yang sudah dibahas) kita melihat bahwa file ini secara garis besar dibagi menjadi dua bagian :
1. Profil datar
2. Grafik panggilan
Kolom individu untuk (profil datar serta grafik panggilan) dijelaskan dengan sangat baik dalam output itu sendiri.
Sesuaikan keluaran gprof menggunakan tanda
Ada berbagai tanda yang tersedia untuk menyesuaikan keluaran alat gprof. Beberapa di antaranya dibahas di bawah ini:
1. Menekan pencetakan fungsi yang dideklarasikan secara statis (pribadi) menggunakan -a
Jika ada beberapa fungsi statis yang informasi profilnya tidak Anda perlukan, maka ini dapat dicapai dengan menggunakan opsi -a :
$ gprof -a test_gprof gmon.out > analysis.txt
Sekarang jika kita melihat file analisis itu :
Flat profile:
Each sample counts as 0.01 seconds.
% cumulative self self total
time seconds seconds calls s/call s/call name
67.15 30.77 30.77 2 15.39 23.14 func1
33.82 46.27 15.50 1 15.50 15.50 new_func1
0.07 46.30 0.03 main
...
...
...
Call graph (explanation follows)
granularity: each sample hit covers 2 byte(s) for 0.02% of 46.30 seconds
index %time self children called name
[1] 100.0 0.03 46.27 main [1]
30.77 15.50 2/2 func1 [2]
-----------------------------------------------------
30.77 15.50 2/2 main [1]
[2] 99.9 30.77 15.50 2 func1 [2]
15.50 0.00 1/1 new_func1 [3]
----------------------------------------------------
15.50 0.00 1/1 func1 [2]
[3] 33.5 15.50 0.00 1 new_func1 [3]
-----------------------------------------------
...
...
... Jadi kita melihat bahwa tidak ada informasi yang berhubungan dengan func2 (yang didefinisikan statis)
2. Menekan uraian panjang lebar menggunakan -b
Seperti yang sudah Anda lihat bahwa gprof menghasilkan output dengan banyak informasi verbose, jadi jika informasi ini tidak diperlukan maka ini dapat dicapai dengan menggunakan flag -b.
$ gprof -b test_gprof gmon.out > analysis.txt
Sekarang jika kita melihat file analisis :
Flat profile:
Each sample counts as 0.01 seconds.
% cumulative self self total
time seconds seconds calls s/call s/call name
33.86 15.52 15.52 1 15.52 15.52 func2
33.82 31.02 15.50 1 15.50 15.50 new_func1
33.29 46.27 15.26 1 15.26 30.75 func1
0.07 46.30 0.03 main
Call graph
granularity: each sample hit covers 2 byte(s) for 0.02% of 46.30 seconds
index % time self children called name
[1] 100.0 0.03 46.27 main [1]
15.26 15.50 1/1 func1 [2]
15.52 0.00 1/1 func2 [3]
-----------------------------------------------
15.26 15.50 1/1 main [1]
[2] 66.4 15.26 15.50 1 func1 [2]
15.50 0.00 1/1 new_func1 [4]
-----------------------------------------------
15.52 0.00 1/1 main [1]
[3] 33.5 15.52 0.00 1 func2 [3]
-----------------------------------------------
15.50 0.00 1/1 func1 [2]
[4] 33.5 15.50 0.00 1 new_func1 [4]
-----------------------------------------------
Index by function name
[2] func1 [1] main
[3] func2 [4] new_func1 Jadi kami melihat bahwa semua informasi verbose tidak ada dalam file analisis.
3. Cetak hanya profil datar menggunakan -p
Jika hanya profil datar yang diperlukan maka :
$ gprof -p -b test_gprof gmon.out > analysis.txt
Perhatikan bahwa saya telah menggunakan (dan akan menggunakan) opsi -b untuk menghindari informasi tambahan dalam hasil analisis.
Sekarang jika kita melihat hasil analisis tersebut:
Flat profile: Each sample counts as 0.01 seconds. % cumulative self self total time seconds seconds calls s/call s/call name 33.86 15.52 15.52 1 15.52 15.52 func2 33.82 31.02 15.50 1 15.50 15.50 new_func1 33.29 46.27 15.26 1 15.26 30.75 func1 0.07 46.30 0.03 main
Jadi kita melihat bahwa hanya profil datar yang ada di output.
4. Cetak informasi terkait fungsi tertentu dalam profil datar
Ini dapat dicapai dengan memberikan nama fungsi bersama dengan opsi -p:
$ gprof -pfunc1 -b test_gprof gmon.out > analysis.txt
Sekarang jika kita melihat output analisis itu :
Flat profile: Each sample counts as 0.01 seconds. % cumulative self self total time seconds seconds calls s/call s/call name 103.20 15.26 15.26 1 15.26 15.26 func1
Jadi kita melihat profil datar yang berisi informasi yang terkait dengan fungsi hanya fungsi1 yang ditampilkan.
5. Menekan profil datar dalam output menggunakan -P
Jika profil datar tidak diperlukan maka dapat ditekan menggunakan opsi -P :
$ gprof -P -b test_gprof gmon.out > analysis.txt
Sekarang jika kita melihat output analisis :
Call graph granularity: each sample hit covers 2 byte(s) for 0.02% of 46.30 seconds
index % time self children called name
[1] 100.0 0.03 46.27 main [1]
15.26 15.50 1/1 func1 [2]
15.52 0.00 1/1 func2 [3]
-----------------------------------------------
15.26 15.50 1/1 main [1]
[2] 66.4 15.26 15.50 1 func1 [2]
15.50 0.00 1/1 new_func1 [4]
-----------------------------------------------
15.52 0.00 1/1 main [1]
[3] 33.5 15.52 0.00 1 func2 [3]
-----------------------------------------------
15.50 0.00 1/1 func1 [2]
[4] 33.5 15.50 0.00 1 new_func1 [4]
-----------------------------------------------
Index by function name
[2] func1 [1] main
[3] func2 [4] new_func1 Jadi kami melihat bahwa profil datar ditekan dan hanya grafik panggilan yang ditampilkan di output.
Juga, jika ada persyaratan untuk mencetak profil datar tetapi mengecualikan fungsi tertentu maka ini juga dimungkinkan menggunakan flag -P dengan meneruskan nama fungsi (untuk mengecualikan) bersamanya.
$ gprof -Pfunc1 -b test_gprof gmon.out > analysis.txt
Dalam contoh di atas, kami mencoba mengecualikan 'func1' dengan meneruskannya bersama dengan opsi -P ke gprof. Sekarang mari kita lihat hasil analisisnya:
Flat profile: Each sample counts as 0.01 seconds. % cumulative self self total time seconds seconds calls s/call s/call name 50.76 15.52 15.52 1 15.52 15.52 func2 50.69 31.02 15.50 1 15.50 15.50 new_func1 0.10 31.05 0.03 main
Jadi kami melihat bahwa profil datar ditampilkan tetapi informasi tentang func1 disembunyikan.
6. Cetak hanya informasi grafik panggilan menggunakan -q
gprof -q -b test_gprof gmon.out > analysis.txt
Dalam contoh di atas, opsi -q digunakan. Mari kita lihat apa pengaruhnya pada hasil analisis:
Call graph
granularity: each sample hit covers 2 byte(s) for 0.02% of 46.30 seconds
index % time self children called name
[1] 100.0 0.03 46.27 main [1]
15.26 15.50 1/1 func1 [2]
15.52 0.00 1/1 func2 [3]
-----------------------------------------------
15.26 15.50 1/1 main [1]
[2] 66.4 15.26 15.50 1 func1 [2]
15.50 0.00 1/1 new_func1 [4]
-----------------------------------------------
15.52 0.00 1/1 main [1]
[3] 33.5 15.52 0.00 1 func2 [3]
-----------------------------------------------
15.50 0.00 1/1 func1 [2]
[4] 33.5 15.50 0.00 1 new_func1 [4]
-----------------------------------------------
Index by function name
[2] func1 [1] main
[3] func2 [4] new_func1 Jadi kita melihat bahwa hanya grafik panggilan yang dicetak di output.
7. Cetak hanya informasi fungsi tertentu dalam grafik panggilan.
Ini dimungkinkan dengan meneruskan nama fungsi bersama dengan opsi -q.
$ gprof -qfunc1 -b test_gprof gmon.out > analysis.txt
Sekarang jika kita melihat output analisis:
Call graph
granularity: each sample hit covers 2 byte(s) for 0.02% of 46.30 seconds
index % time self children called name
15.26 15.50 1/1 main [1]
[2] 66.4 15.26 15.50 1 func1 [2]
15.50 0.00 1/1 new_func1 [4]
-----------------------------------------------
15.50 0.00 1/1 func1 [2]
[4] 33.5 15.50 0.00 1 new_func1 [4]
-----------------------------------------------
Index by function name
[2] func1 (1) main
(3) func2 [4] new_func1 Jadi kita melihat bahwa informasi yang terkait dengan fungsi1 saja yang ditampilkan dalam grafik panggilan.
8. Menekan grafik panggilan menggunakan -Q
Jika informasi grafik panggilan tidak diperlukan dalam output analisis, maka opsi -Q dapat digunakan.
$ gprof -Q -b test_gprof gmon.out > analysis.txt
Sekarang jika kita melihat output analisis :
Flat profile: Each sample counts as 0.01 seconds. % cumulative self self total time seconds seconds calls s/call s/call name 33.86 15.52 15.52 1 15.52 15.52 func2 33.82 31.02 15.50 1 15.50 15.50 new_func1 33.29 46.27 15.26 1 15.26 30.75 func1 0.07 46.30 0.03 main
Jadi kita melihat bahwa hanya profil datar yang ada di output. Seluruh grafik panggilan ditekan.
Juga, jika diinginkan untuk menekan fungsi tertentu dari grafik panggilan, maka ini dapat dicapai dengan meneruskan nama fungsi yang diinginkan bersama dengan opsi -Q ke alat gprof.
$ gprof -Qfunc1 -b test_gprof gmon.out > analysis.txt
Dalam contoh di atas, nama fungsi func1 diteruskan ke opsi -Q.
Sekarang jika kita melihat output analisis:
Call graph
granularity: each sample hit covers 2 byte(s) for 0.02% of 46.30 seconds
index % time self children called name
[1] 100.0 0.03 46.27 main [1]
15.26 15.50 1/1 func1 [2]
15.52 0.00 1/1 func2 [3]
-----------------------------------------------
15.52 0.00 1/1 main [1]
[3] 33.5 15.52 0.00 1 func2 [3]
-----------------------------------------------
15.50 0.00 1/1 func1 [2]
[4] 33.5 15.50 0.00 1 new_func1 [4]
-----------------------------------------------
Index by function name
(2) func1 [1] main
[3] func2 [4] new_func1 Jadi kami melihat bahwa informasi grafik panggilan yang terkait dengan func1 telah disembunyikan.