CPU Analysis
현재 CPU 정보 확인하기
CPU core 별 clock 확인하기
cat /sys/devices/system/cpu/cpu*/cpufreq/scaling_max_freq uptime
시스템 부하 평균을 표시한다. load average의 값은 앞에서부터 1분, 5분, 15분 동안의 평균 부하이다.
uptime
08:41:55 up 1 day, 17:41, 4 users, load average: 0.28, 0.24, 0.27부하평균은 CPU 자원에 대한 요구사항으로써, ** 실행 중인 스레드 개수 + 대기열의 스레드 개수 **이다. 만약 부하 평균이 호스트 머신의 CPU 개수보다 크면 스레드를 처리하기에 CPU가 부족한 상황이며, 대기열에 여러 스레드가 CPU를 할당받기 위해 대기하고 있는 상태라고 파악할 수 있다.
vmstat
vmstat은 가상 메모리 통계 정보를 제공한다.
$vmstat
procs -----------memory---------- ---swap-- -----io---- -system-- ------cpu-----
r b swpd free buff cache si so bi bo in cs us sy id wa st
0 0 1024 12837676 7238384 10378596 0 0 14 39 24 19 2 1 97 0 0위 컬럼에서 아래 정보에서 각 컬럼에 대한 내용은 아래와 같다.
- r : 실행 중이거나 실행을 위해 기다리는 프로세스 개수
- us : 사용자 시간
- sy : 시스템 시간
- id : 유휴
- wa : I/O 대기. 스레드가 디스크 I/O를 기다리느라 블록된 것을 표시
mpstat (multiprocessor statistics tool)
CPU 별 통계 확인 가능
mpstat -P ALL 1
Linux 4.15.0-76-generic (linuxias) 2020년 02월 17일 _x86_64_ (8 CPU)
CPU %usr %nice %sys %iowait %irq %soft %steal %guest %gnice %idle
all 5.02 0.00 7.78 0.00 0.00 0.00 0.00 0.00 0.00 87.20
0 0.99 0.00 1.98 0.00 0.00 0.00 0.00 0.00 0.00 97.03
1 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00 100.00
2 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00 100.00
3 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00 100.00
4 37.62 0.00 59.41 0.00 0.00 0.00 0.00 0.00 0.00 2.97
5 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00 100.00
6 0.00 0.00 1.01 0.00 0.00 0.00 0.00 0.00 0.00 98.99
7 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00 100.00
mpstat을 실행한 호스트머신에는 8개의 CPU가 있으며 각 통계정보는 위와 같다. 각 정보가 표시하는 내역은 다음과 같다.
- CPU : 논리적 CPU ID
- %usr : 사용자 시간
- %nice : nice가 지정된 프로세스의 사용자 시간
- %sys : 시스템 시간
- %iowatit : I/O 대기
- %irq : 하드웨어 인터럽트 CPU 사용률
- %soft : 소프트웨어 인터럽트 CPU 사용률
- %guest : 게스트 가상 머신을 실행하는데 사용한 시간
- %idle : 유휴 시간
위 정보를 기반으로 현재 호스트머신의 대부분의 CPU는 idle 상태이며, 4번 CPU에서 특정한 작업이 이뤄지고 있고 있음을 알 수 있다. usr / sys / idle 항목을 잘 확인하면 CPU 별 CPU 사용률과 사용자, 커널 사용 시간에 대한 비율을 확인할 수 있다. 사용자 어플리케이션이 코드를 실행하는 데 소모한 CPU 시간이 usr 이며, 커널 영역 코드 실행하는데 걸린 시간이 sys이다. 커널 시간에는 시스템 콜 처리 시간, 커널 스레드가 보낸 시간, 인터럽트 처리 시간 등이 포함된다.
sar (system activity reporter)
sar 는 mpstat와 유사하게 사용되며 현재 시스템 상태를 관찰하고, 과거 통계 정보를 저장하도록 할 수 있다. 각 항목은 위에서 설명한 항목과 유사하다.
sar -P ALL 1
Linux 4.15.0-76-generic (linuxias) 2020년 02월 17일 _x86_64_ (8 CPU)
CPU %user %nice %system %iowait %steal %idle
all 5.75 0.00 8.12 0.00 0.00 86.12
0 3.00 0.00 5.00 0.00 0.00 92.00
1 0.99 0.00 0.99 0.00 0.00 98.02
2 7.92 0.00 7.92 0.00 0.00 84.16
3 1.00 0.00 0.00 0.00 0.00 99.00
4 1.98 0.00 2.97 0.99 0.00 94.06
5 0.00 0.00 2.02 0.00 0.00 97.98
6 30.69 0.00 44.55 0.00 0.00 24.75
7 0.99 0.00 1.98 0.00 0.00 97.03
perf (Performance Counters for Linux)
perf는 다양한 옵션이 존재하지만 그 중 몇가지 항목에 대해서만 정리해보려 한다.
| Command | Description |
|---|---|
record |
명령어를 실행하고 결과를 perf.data 파일에 저장한다. |
report |
perf.data 파일을 읽어 결과를 출력한다. |
sched |
스케쥴러 트레이싱을 위한 툴 |
stat |
통계 정보 |
시스템 프로파일링
perf는 CPU 호출 경로를 프로파일링 할 때 자주 사용된다. 아래는 시스템 프로파일링에 대한 예시이다.record의 -a 옵션은 모든 CPU, -g는 호출 스택, -F 997 는 샘플링 주기를 997Hz로 sleep 10은 10초 간 기록하라라는 의미이다.record로 저장한 데이터를 report로 출력하게 되면 트리 형태로 표현된다. 너무 길어 아래 부분은 생략한다.
$sudo perf record -a -g -F 997 sleep 10
[ perf record: Woken up 1 times to write data ]
[ perf record: Captured and wrote 2.024 MB perf.data (3722 samples) ]
$sudo perf report --stdio
# To display the perf.data header info, please use --header/--header-only options.
#
#
# Total Lost Samples: 15
#
# Samples: 3K of event 'cycles:ppp'
# Event count (approx.): 2728432762
#
# Children Self Command Shared Object Symbol
# ........ ........ ............... ........................... ............................
#
62.00% 0.00% swapper [kernel.kallsyms] [k] secondary_startup_64
|
---secondary_startup_64
|
|--56.13%--start_secondary
| cpu_startup_entry
| |
| --55.96%--do_idle
| |
| |--47.86%--call_cpuidle
| | cpuidle_enter
| | |
| | --47.85%--cpuidle_enter_state
| | |
| | |--34.77%--intel_idle
| | |
| | |--7.11%--apic_timer_interrupt
.......위 트리구조를 해석하면 전체 정보는 샘플 크기가 작아지는 순서대로 표시된다. 가장 많이 CPU를 사용한 스레드는 swapper(유휴 스레드)이다. 트리의 내부에서 표현되는 %는 CPU 전체가 아니다. 위에서 cpuidle_enter_State가 47.85%이고 자식 중 intel idle이 34.77%라면, intel idle 이 47.85% 중 34.77%를 차지한다는 의미이다.
특정 프로세스 프로파일링
perf record -g [command] // 프로세스 실행하며 프로파일링 시작
perf record -g -p [pid] // 실행 중신 프로세스 프로파일링 시작htop 프로세스를 실행하고 -p 옵션으로 프로파일링 하는 예시는 아래와 같다.
$sudo perf record -g -p `pidof htop` sleep 5
$sudo perf report --stdio
# To display the perf.data header info, please use --header/--header-only options.
#
#
# Total Lost Samples: 2
#
# Samples: 50 of event 'cycles:ppp'
# Event count (approx.): 309981392
#
# Children Self Command Shared Object Symbol
# ........ ........ ....... ................. ....................................................
#
64.87% 64.87% htop [kernel.kallsyms] [k] syscall_return_via_sysret
|
|--57.82%--0x30d8f70400000006
| __close_nocancel
| syscall_return_via_sysret
|
--6.93%--__GI___libc_read
syscall_return_via_sysret
62.48% 0.00% htop libc-2.23.so [.] __close_nocancel
|
---__close_nocancel
|
|--57.82%--syscall_return_via_sysret
|
--4.42%--__entry_trampoline_start
57.82% 0.00% htop [unknown] [k] 0x30d8f70400000006
|
---0x30d8f70400000006
__close_nocancel
syscall_return_via_sysret
25.35% 0.00% htop libc-2.23.so [.] __GI___libc_read
26....스케줄러 프로파일링
sched 옵션을 이용하여 스케쥴러 정보를 확인할 수 있다. 아래에서 사용한 latency 옵션은 각 태스크 스케쥴링 레이턴시들에 대해 정보를 제공한다. 그 외에도 script, replay, map 옵션이 있다. 자세한 내용은 man perf sched 에서 확인하면 된다.
$sudo perf sched record sleep 3
[ perf record: Woken up 2 times to write data ]
[ perf record: Captured and wrote 6.090 MB perf.data (40024 samples) ]
$ sudo perf sched latency
-----------------------------------------------------------------------------------------------------------------
Task | Runtime ms | Switches | Average delay ms | Maximum delay ms | Maximum delay at |
-----------------------------------------------------------------------------------------------------------------
perf:2215 | 5.191 ms | 1 | avg: 0.032 ms | max: 0.032 ms | max at: 89323.211980 s
lttng-sessiond:17440 | 0.101 ms | 3 | avg: 0.032 ms | max: 0.033 ms | max at: 89321.697742 s
avahi-daemon:1119 | 8.777 ms | 54 | avg: 0.028 ms | max: 0.041 ms | max at: 89322.788970 s
kworker/1:0:28740 | 0.159 ms | 8 | avg: 0.026 ms | max: 0.033 ms | max at: 89322.372042 s
kworker/3:0:28203 | 0.028 ms | 1 | avg: 0.025 ms | max: 0.025 ms | max at: 89320.908025 s
kworker/0:1:30386 | 0.096 ms | 3 | avg: 0.025 ms | max: 0.033 ms | max at: 89322.872069 s
kworker/7:0:31054 | 0.154 ms | 5 | avg: 0.024 ms | max: 0.031 ms | max at: 89322.780055 s
NioBlockingSele:1018 | 0.086 ms | 3 | avg: 0.023 ms | max: 0.033 ms | max at: 89320.871888 s
/usr/bin/x-term:7180 | 1.292 ms | 6 | avg: 0.022 ms | max: 0.037 ms | max at: 89322.676333 s
Xorg:4299 | 4.470 ms | 35 | avg: 0.021 ms | max: 0.034 ms | max at: 89322.809583 s
whale:8519 | 0.513 ms | 5 | avg: 0.021 ms | max: 0.033 ms | max at: 89322.219984 s
.....
sleep:2220 | 0.926 ms | 2 | avg: 0.007 ms | max: 0.010 ms | max at: 89323.211755 s
ksoftirqd/7:52 | 0.041 ms | 2 | avg: 0.005 ms | max: 0.006 ms | max at: 89320.924052 s
systemd-journal:340 | 0.043 ms | 1 | avg: 0.005 ms | max: 0.005 ms | max at: 89320.290112 s
zeitgeist-datah:6956 | 0.209 ms | 4 | avg: 0.005 ms | max: 0.009 ms | max at: 89320.836458 s
kworker/u16:1:1956 | 6.535 ms | 810 | avg: 0.002 ms | max: 0.037 ms | max at: 89321.088060 s
kworker/u16:2:583 | 36.616 ms | 5468 | avg: 0.002 ms | max: 0.044 ms | max at: 89322.384987 s
-----------------------------------------------------------------------------------------------------------------
TOTAL: | 163.575 ms | 9981 |
---------------------------------------------------
위 결과는 트레이싱 하는 동안의 평균과 최대 스케쥴러 지연시간을 나타낸다. 가장 위에 perf가 표시되는 이유는 트레이싱 동작 자체가 CPU와 저장장치들을 많이 사용함에 따른 비용이다. perf sched latency 뒤에 다양한 옵션이 들어 갈 수 있으므로 그거 또한 직접 확인해 보면 좋다.
통계 정보 확인하기 (stat)
stat은 CPC(CPU Performance Cycle)를 기반으로 CPU 사이클에 대한 통계 정보를 제공한다. 특정 프로세스를 실행하여 분석을 할 수도 있으며 전체에 대해 추적할 수도 있다. 아래는 df -h 명령어에 대한 통계 정보를 확인한 것 이다. 결과를 확인하면 CPU 사용, 컨텍스트 스위칭 횟수, 및 시간, 페이지 폴트, CPU 마이그레이션, 명령어를 수행하는데 사용한 싸이클 등 다양한 정보가 제공된다.
$sudo perf stat df -h
...
Performance counter stats for 'df -h':
1.73 msec task-clock # 0.813 CPUs utilized
0 context-switches # 0.000 K/sec
0 cpu-migrations # 0.000 K/sec
80 page-faults # 0.046 M/sec
3,207,136 cycles # 1.849 GHz
1,874,078 stalled-cycles-frontend # 58.43% frontend cycles idle
2,999,986 instructions # 0.94 insn per cycle
# 0.62 stalled cycles per insn
635,894 branches # 366.542 M/sec
19,691 branch-misses # 3.10% of all branches
0.002134928 seconds time elapsed
0.002180000 seconds user
0.000000000 seconds sys
이벤트 이용하여 통계 정보 확인하기
perf는 확인할 수 있는 다양한 이벤트 리스트를 제공한다. perf list를 통해 확인해 보자. 그 중 CPU와 관련된 많은 이벤트들도 존재한다. 몇몇 이벤트를 선별하여 테스트 해보자. 아래와 같이 본인이 원하는 이벤트에 대한 결과만 확인할 수 있따.
$sudo perf stat -e instructions,cycles,cache-misses du -a -h
Performance counter stats for 'du -a -h':
2,296,353,620 instructions # 0.65 insn per cycle
# 0.00 stalled cycles per insn
3,543,461,302 cycles
2,002,191 cache-misses
1.769061539 seconds time elapsed
0.331797000 seconds user
0.659498000 seconds sysReference
- 시스템 성능 분석과 최적화 | 브렌든 그레그 지음, 오현석, 서형국 옮김 | 위키북스
- Perf Manual page
'Linux > Profiling' 카테고리의 다른 글
| Performance Methodologies (0) | 2021.02.04 |
|---|---|
| Memory Profiling (0) | 2021.02.04 |
| [Profiling Tool] LTTng (0) | 2021.02.04 |
| File System Profiling (0) | 2021.02.04 |
| ftrace (0) | 2021.02.04 |