TL;DR:fooプロファイリング イベントを取得するには高速で小さいため、さらに 100 回実行します。周波数設定にタイプミスがありpprof、CONFIG_HZ (通常は 250) よりも頻繁にサンプリングされません。より最新の Linuxperfプロファイラーに切り替えることをお勧めします (その作成者によるチュートリアル、wikipedia )。
長いバージョン:
あなたのfoo関数は短すぎて単純すぎます.2つの関数を呼び出すだけです. でテストをコンパイルし、プログラムg++ test.cc -lprofiler -o test.s -S -gでフィルタリングtest.sしc++filtて c++ の名前を読みやすくしました。
foo():
.LFB972:
.loc 1 27 0
pushq %rbp
movq %rsp, %rbp
.loc 1 28 0
movl $.LC0, %esi
movl std::cout, %edi
call std::basic_ostream<char, std::char_traits<char> >& std::operator<< <std::char_traits<char> >(std::basic_ostream<char, std::char_traits<char> >&, char const*)
movl std::basic_ostream<char, std::char_traits<char> >& std::endl<char, std::char_traits<char> >(std::basic_ostream<char, std::char_traits<char> >&), %esi
movq %rax, %rdi
call std::basic_ostream<char, std::char_traits<char> >::operator<<(std::basic_ostream<char, std::char_traits<char> >& (*)(std::basic_ostream<char, std::char_traits<char> >&))
.loc 1 29 0
popq %rbp
ret
.LFE972:
.size foo(), .-foo()
したがって、プロファイルでそれを確認するには、より多くの時間を実行する必要があります。主に、10000 またはより良い 100000 など、より大きな値にfoo変更します (テストで私が行ったように)。int a = 1000;
また、間違った " CPUPROFILE_FREQUENC=10000" を修正して修正することもできますCPUPROFILE_FREQUENCY( に注意してくださいY)。10000 は CPUPROFILE_FREQUENCY の設定が高すぎると言わざるを得ません。これは、通常、カーネルの構成に応じて 1 秒あたり 1000 または 250 のイベントしか生成しない場合があるためですCONFIG_HZ(ほとんどの 3.x カーネルでは 250 です。確認してくださいgrep CONFIG_HZ= /boot/config*)。また、pprof の CPUPROFILE_FREQUENCY のデフォルト設定は 100 です。
CPUPROFILE_FREQUENCY のさまざまな値をテストしました: 100000、10000、1000、250 Ubuntu 14.04 で bash スクリプトを使用
for a in 100000 100000 10000 10000 1000 1000 300 300 250 250; do
echo -n "$a ";
CPUPROFILE_FREQUENCY=$a CPUPROFILE=dump$a.txt ./test >/dev/null;
done
そして、結果は同じ 120-140 のイベントと約 0.5 秒ごとの ./test のランタイムであったため、google-perftools の cpuprofiler は、カーネルで設定された CONFIG_HZ よりも、単一のスレッドに対して 1 秒あたりより多くのイベントを実行できません (私の場合は 250 です)。
100000 PROFILE: interrupts/evictions/bytes = 124/1/6584
100000 PROFILE: interrupts/evictions/bytes = 134/0/7864
10000 PROFILE: interrupts/evictions/bytes = 125/0/7488
10000 PROFILE: interrupts/evictions/bytes = 123/0/6960
1000 PROFILE: interrupts/evictions/bytes = 134/0/6264
1000 PROFILE: interrupts/evictions/bytes = 125/2/7272
300 PROFILE: interrupts/evictions/bytes = 137/2/7984
300 PROFILE: interrupts/evictions/bytes = 126/0/7216
250 PROFILE: interrupts/evictions/bytes = 123/3/6680
250 PROFILE: interrupts/evictions/bytes = 137/2/7352
元の a=1000 ではfoo、cout の関数は実行のたびにプロファイリング イベント (250 イベント/秒であっても) を取得するには速すぎるためfoo、 も入力/出力関数もありません。少量の実行では、__write_nocancelサンプリング イベントが発生する可能性があり、foo libstdc++ からの I/O 関数が報告されます (最上位ではない場所にあるため、 or--textのオプションを使用します) 自己イベント カウントがゼロで、子イベントがゼロ以外の場合カウント：pprofgoogle-pprof
....
1 0.9% 99.1% 1 0.9% __write_nocancel
....
0 0.0% 100.0% 1 0.9% _IO_new_file_overflow
0 0.0% 100.0% 1 0.9% _IO_new_file_write
0 0.0% 100.0% 1 0.9% __GI__IO_putc
0 0.0% 100.0% 1 0.9% foo
0 0.0% 100.0% 1 0.9% new_do_write
0 0.0% 100.0% 1 0.9% std::endl
0 0.0% 100.0% 1 0.9% std::ostream::put
を使用a=100000すると、foo はまだ短すぎて高速すぎて独自のイベントを取得できませんが、I/O 関数はいくつかのイベントを取得します。これは、長い--text出力から grep したリストです。
34 24.6% 24.6% 34 24.6% __write_nocancel
1 0.7% 95.7% 35 25.4% __GI__IO_fflush
1 0.7% 96.4% 1 0.7% __GI__IO_putc
1 0.7% 97.8% 2 1.4% std::operator<<
1 0.7% 98.6% 36 26.1% std::ostream::flush
1 0.7% 99.3% 2 1.4% std::ostream::put
0 0.0% 100.0% 34 24.6% _IO_new_file_sync
0 0.0% 100.0% 34 24.6% _IO_new_file_write
0 0.0% 100.0% 40 29.0% foo
0 0.0% 100.0% 34 24.6% new_do_write
0 0.0% 100.0% 2 1.4% std::endl
独自のカウンターがゼロの関数は、呼び出しチェーンを読み取る機能のおかげでのみ表示されpprofます (フレーム情報が省略されていない場合、サンプルを取得した関数を誰が呼び出しているかがわかります)。
また、より最新で、より機能的 (ソフトウェア イベントとハードウェア イベントの両方、最大 5 kHz 以上の周波数。ユーザー空間とカーネル プロファイリングの両方) で、よりサポートされているプロファイラーである Linuxperfプロファイラー (作者によるチュートリアル、wikipedia ) をお勧めします。
perfからの結果がありますa=10000:
$ perf record ./test3 >/dev/null
... skip some perf's spam about inaccessibility of kernel symbols
... note the 3 kHz frequency here VVVV
Lowering default frequency rate to 3250.
Please consider tweaking /proc/sys/kernel/perf_event_max_sample_rate.
[ perf record: Woken up 1 times to write data ]
[ perf record: Captured and wrote 0.078 MB perf.data (~3386 samples) ]
perf.data出力ファイルからテキスト レポートを表示するには、less を使用perf reportします (デフォルトでインタラクティブなプロファイル ブラウザーが起動するため)。
$ perf report |less
... skip some extra info about the machine, kernel, and perf starting command
# Samples: 1K of event 'cycles'
# Event count (approx.): 1155264208
# Overhead Command Shared Object Symbol
41.94% test3 libm-2.19.so [.] __tan_sse2
16.95% test3 libm-2.19.so [.] __sin_sse2
13.40% test3 libm-2.19.so [.] __cos_sse2
4.93% test3 test3 [.] bar()
2.90% test3 libc-2.19.so [.] __GI___libc_write
....
0.20% test3 test3 [.] foo()
またはperf report -n | less、未加工のイベント (サンプル) カウンターを表示するには:
# Overhead Samples Command Shared Object
41.94% 663 test3 libm-2.19.so [.] __tan_sse2
16.95% 268 test3 libm-2.19.so [.] __sin_sse2
13.40% 212 test3 libm-2.19.so [.] __cos_sse2
4.93% 78 test3 test3 [.] bar()
2.90% 62 test3 libc-2.19.so [.] __GI___libc_write
....
0.20% 4 test3 test3 [.] foo()