TL : foo
은 프로파일 링 이벤트를 얻기 위해 빠르다가 작고 100 번 더 실행합니다. 빈도 설정은 오타가 있었으며 pprof
은 CONFIG_HZ (보통 250)보다 더 자주 샘플링하지 않습니다. 보다 현대적인 리눅스 perf
프로파일 러 (tutorial from its authors, wikipedia)로 전환하는 것이 좋습니다.
긴 버전 :
이
귀하의 foo
기능이 너무 짧고 간단합니다 - 두 함수를 호출. 훨씬 더 큰 무언가에 주에 int a = 1000;
을 변경,
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()
그래서, 당신은 더 번 foo
를 실행해야합니다 프로필에서 볼 수 : 읽을 C++ 이름을 만들 수 c++filt
프로그램 test.s
의 필터링 g++ test.cc -lprofiler -o test.s -S -g
테스트를 컴파일 , 10000 또는 더 나은 100000처럼 (나는 시험을 위해 한 것처럼).
도 있습니다 (Y
주의) CPUPROFILE_FREQUENCY
를 해결하려면 "CPUPROFILE_FREQUENC=10000
"잘못된를 해결할 수 있습니다. 커널 구성 CONFIG_HZ
에 따라 초당 1000 또는 250 개의 이벤트를 생성 할 수 있기 때문에 10000은 CPUPROFILE_FREQUENCY 설정이 너무 높습니다 (대부분 3.x 커널은 250, 확인 grep CONFIG_HZ= /boot/config*
). pprof의 CPUPROFILE_FREQUENCY에 대한 기본 설정은 100입니다.
우분투 14에서 bash 스크립트를 사용하여 CPUPROFILE_FREQUENCY : 100000, 10000, 1000, 250의 다른 값을 테스트했습니다.
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
04 그리고 그 결과는 CONFIG_HZ 세트보다는 하나의 스레드에 대한 초당 이벤트를 할 수 없어 구글 - perftools에서 같은 120-140 이벤트와 약 0.5 초마다 ./test의 실행, 그래서 cpuprofiler했다 커널에서 (my has 250). 원래 A = 1000 개 foo
와 COUT의 기능
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
은 더 foo
이 없다, 그래서 모든 실행에 그들에있는 프로파일 이벤트 (심지어 250 이벤트/S)를 얻기 위해 너무 빨리 실행하거나 임의의 입력/출력 기능 . 적은 양의 실행에서는 __write_nocancel
에 샘플링 이벤트가 발생했을 수 있으며 foo
이 있고 libstdC++ 형식의 I/O 함수가보고됩니다 (가장 위에 있지 않으므로 --text
옵션을 pprof
또는 google-pprof
으로 사용).
a=100000
와
....
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
가, foo는 여전히 자신의 이벤트를 가져 너무 짧고 빠르게,하지만 난/O 기능이 몇 가지 있어요 : 비 제로 하위 이벤트는 계산합니다. 제로 자신의 카운터
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
기능에 볼 : 이것은 내가 오랫동안 --text
출력에서 grepped 목록입니다 .
나는 또한 현대, 더 많은 능력 추천 할 수
(모두 소프트웨어 및 하드웨어 이벤트를 5 kHz의 주파수 이상, 모두 사용자 공간과 커널 프로파일 링)과 더 나은 지원 프로파일, 리눅스 perf
프로파일 러 (tutorial from its authors, wikipedia) .
는 perf
에서 a=10000
과 결과가 있습니다
$ 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 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 report
) 이하를 사용합니다 perf.data
출력 파일에서 텍스트 보고서를 보려면 또는 원시 이벤트 (샘플) 카운터를 보려면 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()
"CPUPROFILE_FREQUENC = 10000"이라고했지만 Y가 누락되었다고 했으므로 실제 (무시 된) 경우 작은 foo를 표시 할 수있는 샘플이 충분하지 않을 수 있습니다. – mgkrebbs
벽시계 시간이 아닌 CPU 시간을보고 있습니다. 'foo'가 사용하는 CPU 시간은 거의 없습니다. I/O를 수행하는 라이브러리 함수를 호출하고 I/O를 수행하는 동안 CPU 샘플이 발생하지 않습니다. –