gprofを使用してコードをプロファイリングする方法を学んでいます。私のアプリケーションの1つについて、次の出力があります。
Each sample counts as 0.01 seconds.
% cumulative self self total
time seconds seconds calls ms/call ms/call name
10.27 1.20 1.20 Location::get_type() const (location.cpp:20 @ 40a4bd)
さらに下にこれが見えます
1.20 4.98 0.14 34662692 0.00 0.00 Location::get_type() const (location.cpp:19 @ 40a4ac)
これが機能です
char Location::get_type() const {
return type;
}
gprofの最初の行は関数の実行に必要な合計時間を示し、2番目の行はreturnステートメントに必要な時間だけを示していると想定しています。sを返す同じクラスのゲッターである他の関数がint
ありますが、関数時間とreturnステートメント時間の差は約0.1秒ですが、投稿した時間と同様に、時差は1.06秒です(他のゲッターは約200万分の1の通話で、通話の総数に比べると少ないです)。1行のコードではなく、関数呼び出しの時間が長くなる理由は何でしょうか。
行ごとのモードでgprofを使用しているので、-g-pgを使用してコンパイルしたことは言及する価値があるかもしれません。
編集:答えの1つは、アセンブリの出力を確認することを提案しました。理解できないので、ここに投稿します。2つの関数呼び出しのアセンブリコードを投稿しました。最初のものはget_floor()で、これは比較的高速です(〜.10秒)。2つ目は遅いget_type()です。
_ZNK8Location9get_floorEv:
.LFB5:
.cfi_startproc
pushq %rbp
.cfi_def_cfa_offset 16
.cfi_offset 6, -16
movq %rsp, %rbp
.cfi_def_cfa_register 6
movq %rdi, -8(%rbp)
movq -8(%rbp), %rax
movl 8(%rax), %eax
popq %rbp
.cfi_def_cfa 7, 8
ret
.cfi_endproc
.LFE5:
.size _ZNK8Location9get_floorEv, .-_ZNK8Location9get_floorEv
.align 2
.globl _ZNK8Location8get_typeEv
.type _ZNK8Location8get_typeEv, @function
_ZNK8Location8get_typeEv:
.LFB6:
.cfi_startproc
pushq %rbp
.cfi_def_cfa_offset 16
.cfi_offset 6, -16
movq %rsp, %rbp
.cfi_def_cfa_register 6
movq %rdi, -8(%rbp)
movq -8(%rbp), %rax
movzbl 12(%rax), %eax
popq %rbp
.cfi_def_cfa 7, 8
ret
.cfi_endproc