Введение

Начать с:

yum --enablerepo='base-debuginfo' install kernel-debuginfo-`uname -r` kernel-devel perf oprofile gdb kexec-tools crash

если по быстрому

perf top - не точно показывает адрес топ фукнции
- https://perf.wiki.kernel.org/index.php/Tutorial#Sampling_with_perf_record
- perf top -d 5 -U
- perf top -d 5 -g -U
- perf stat -e task-clock,cycles,instructions,cache-references,cache-misses sleep 5
- perf record -a sleep 5 и потом perf report
powertop

если всерьез

oprofile
sysrq
ftrace + debugfs

Общий алгоритм

Привести машину в максимально дефалтное состояние. Проверить и устранить аномалии и вредные настройки, например штормы прерываний, постоянный лог ошибок в dmesg и прочее. Убрать все оптимизации, если они были наугад включены.
Добиться нагрузки на ядро не менее 15-25% процентов
Провести профилирование oprofile
Провести профилирование через sysrq
Найти и подтвердить по коду, что проблема есть
Проверить, что в новых версиях не сделана оптимизация этих функций и подсистем(обычно нет)
Попробовать решить задачу оптимизацией настроек и оборудования и правил и тп workaround
Если невозможно решить оптимизацией настроек, пробуем оптимизировать код, убрать локи добавить хеши усилить параллельность итп.

Как работает профилирование oprofile

В каждом современном процессоре есть внутренние счетчики, которые при прокрутке могу вызвать процессору прерывание nmi - оно немаскируемое через asm cli.
Внутренние прерывания процессора это lapic и обычно профилируем через него.(также можно использовать внешние тактуемые apic-nmi или другие генераторы, но не рекомендуется)
Профилировщик также как и nmi_watchog устанавливает счетчик на event CPU_CLK_UNHALTED. Поэтому нужно выключить nmi_watchog
CPU_CLK_UNHALTED - это счетчик всех инструкций, кроме HLT(=idle) инструкций. И когда сработает скажем 100, то вызовется nmi→nmi_profile(), инфа кладется в буфер ядра.
Потом демон профилировщика забирает эту инфу из буфера ядра и сохраняет в файл.
На основе этого файла можно строить разные отчеты.
Таким образом, мы можем узнать где чаще всего находится процессор.
p.s. Из минусов, очень редко можно получить нормальный стек вызова и есть подозрения на неполную достоверность, возможно из-за корреляций с демоном. opreport -с не всегда помогает тк калбек по факту не сохраняется, а моделируется.

Как работает профилирование osv через sysrq

В sysrq есть возможность печати текущего стека CPU.

# включаем sysrq эмулятор
echo 1 > /proc/sys/kernel/sysrq
# посылаем L чтобы распечатать стеки CPU\\
echo l >/proc/sysrq-trigger

При записи в proc происходит выставление переменной тригера, которая отлавливается в nmi_enter() и печать стека происходит уже там через случайный промежуток времени, тк на ходу это делать нет смысла, ибо мы поймаем только сами себя.
p.s. Из минусов сервер может повиснуть, поэтому делать надо с паузами и синками, чтоб файл успел записаться.
Пример скрипта:

echo 1 > /proc/sys/kernel/sysrq
dmesg -c>/tmp/d1
echo > /tmp/cpu_report
for ((i=0;i<100;i++)); do 
    sync; sleep 1; sync; 
    for ((k=0;k<10;k++)); do 
        echo $i $k
        echo l > /proc/sysrq-trigger
        sleep 1
        dmesg -c >>/tmp/cpu_report
        done
done

[3002759.740760] NMI backtrace for cpu 5
[3002759.740915] CPU 5 <d>Modules linked in: xt_conntrack vhost_net macvtap macvlan kvm_intel kvm vzethdev vznetdev pio_kaio pio_nfs pio_direct pfmt_raw pfmt_ploop1 ploop simfs vzrst vzcpt nfs lockd fscache auth_rpcgss nfs_acl sunrpc vziolimit vzmon ip6table_mangle xt_length xt_hl xt_multiport xt_limit xt_dscp ip_set_list_set(F)(U) ip_set_hash_netportnet(F)(U) ip_set_hash_netport(F)(U) ip_set_hash_netnet(F)(U) ip_set_hash_net(F)(U) ip_set_hash_netiface(F)(U) ip_set_hash_mac(F)(U) ip_set_hash_ipportnet(F)(U) ip_set_hash_ipport(F)(U) ip_set_hash_ipportip(F)(U) ip_set_hash_ipmark(F)(U) ip_set_hash_ipmac(F)(U) ip_set_hash_ip(F)(U) ip_set_bitmap_port(F)(U) ip_set_bitmap_ipmac(F)(U) ip_set_bitmap_ip(F)(U) xt_set(F)(U) ip_set(F)(U) flashcache(F)(U) ipip tunnel4 nf_conntrack_netlink zram(C) lzo_decompress lzo_compress vxlan nfnetlink ebtable_nat ebtables ipt_MASQUERADE iptable_nat xt_CHECKSUM tun bridge stp llc nf_nat vzdquota xt_tcpmss xt_TCPMSS iptable_mangle vzevent vzdev ipt_REJECT nf_conntrack_ipv4 nf_defrag_ipv4 iptable_filter
[3002759.742871] Pid: 0, comm: swapper veid: 0 Tainted: GF        C -- ------------    2.6.32-042stab123.8 #3 042stab123_8<c> Supermicro Super Server<c>/X11SSL-F<c>
[3002759.743306] RIP: 0010:[<ffffffff8130ed31>]  [<ffffffff8130ed31>] intel_idle+0xd1/0x1b0
[3002759.743594] RSP: 0018:ffff8810694dbe48  EFLAGS: 00000046
[3002759.743742] RAX: 0000000000000020 RBX: 0000000000000008 RCX: 0000000000000001
[3002759.744036] RDX: 0000000000000000 RSI: ffff8810694dbfd8 RDI: ffffffff81a989c0
[3002759.744321] RBP: ffff8810694dbed8 R08: 00000000000001e2 R09: 00000000000000fd
[3002759.744606] R10: 0000000000000002 R11: 0000000000000000 R12: 0000000000000004
[3002759.744900] R13: ffff880028366280 R14: 0000000000000020 R15: 150cb8aef998319c
[3002759.745401] FS:  0000000000000000(0000) GS:ffff880028340000(0000) knlGS:0000000000000000
[3002759.745689] CS:  0010 DS: 0018 ES: 0018 CR0: 000000008005003b
[3002759.745847] CR2: 00000000006d4740 CR3: 0000000001a8d000 CR4: 00000000001427e0
[3002759.746132] DR0: 0000000000000000 DR1: 0000000000000000 DR2: 0000000000000000
[3002759.746419] DR3: 0000000000000000 DR6: 00000000fffe0ff0 DR7: 0000000000000400
[3002759.746705] Process swapper (pid: 0, veid: 0, threadinfo ffff8810694d8000, task ffff8810694ce3c0)
[3002759.747003] Stack:
[3002759.747144]  ffff8810694dbe58 ffffffff810152a9 ffff8810694dbe78 ffffffff810b860d
[3002759.747430]  ffff880000000002 0000000000000005 ffff8810694dbe88 ffffffff810b86e1
[3002759.747716]  ffff8810694dbed8 ffffffff81455004 0000000000000000 0000000500075d13
[3002759.748011] Call Trace:
[3002759.748153]  [<ffffffff810152a9>] ? sched_clock+0x9/0x10
[3002759.748302]  [<ffffffff810b860d>] ? sched_clock_cpu+0xcd/0x110
[3002759.748451]  [<ffffffff810b86e1>] ? sched_clock_idle_sleep_event+0x11/0x20
[3002759.748602]  [<ffffffff81455004>] ? menu_select+0x174/0x350
[3002759.748751]  [<ffffffff81453efa>] cpuidle_idle_call+0x7a/0xe0
[3002759.748909]  [<ffffffff8100a046>] cpu_idle+0xb6/0x110
[3002759.749056]  [<ffffffff8154f403>] start_secondary+0x2c0/0x316
[3002759.749206] Code: ff ff a8 08 75 25 31 d2 48 8d 86 38 c0 ff ff 48 89 d1 0f 01 c8 0f ae f0 48 8b 86 38 c0 ff ff a8 08 75 08 b1 01 4c 89 f0 0f 01 c9 <e8> 0a d1 da ff 4c 29 f8 48 89 c7 e8 8f c3 d7 ff 49 89 c6 49 89
[3002759.749650] Call Trace:
[3002759.749792]  <NMI>  <<EOE>>  [<ffffffff810152a9>] ? sched_clock+0x9/0x10
[3002759.749948]  [<ffffffff810b860d>] ? sched_clock_cpu+0xcd/0x110
[3002759.750098]  [<ffffffff810b86e1>] ? sched_clock_idle_sleep_event+0x11/0x20
[3002759.750249]  [<ffffffff81455004>] ? menu_select+0x174/0x350
[3002759.750398]  [<ffffffff81453efa>] cpuidle_idle_call+0x7a/0xe0
[3002759.750548]  [<ffffffff8100a046>] cpu_idle+0xb6/0x110
[3002759.750695]  [<ffffffff8154f403>] start_secondary+0x2c0/0x316
[3002759.750854] Pid: 0, comm: swapper veid: 0 Tainted: GF        C -- ------------    2.6.32-042stab123.8 #3
[3002759.751144] Call Trace:
[3002759.751286]  <NMI>  [<ffffffff81009c77>] ? show_regs+0x27/0x50
[3002759.751435]  [<ffffffff8155b6b9>] ? arch_trigger_all_cpu_backtrace_handler+0x99/0xc0
[3002759.751722]  [<ffffffff8155cf55>] ? notifier_call_chain+0x55/0x80
[3002759.751881]  [<ffffffff8155cfba>] ? atomic_notifier_call_chain+0x1a/0x20
[3002759.759870]  [<ffffffff810b739e>] ? notify_die+0x2e/0x30
[3002759.750018]  [<ffffffff8155a92b>] ? do_nmi+0xdb/0x370
[3002759.750166]  [<ffffffff8155a433>] ? nmi+0x83/0x90
[3002759.750314]  [<ffffffff8130ed31>] ? intel_idle+0xd1/0x1b0
[3002759.750462]  <<EOE>>  [<ffffffff810b5c38>] ? hrtimer_start+0x18/0x20

Полученный файл можно грепать по первому и второму процу, и потом по конкретным вызовам и подвызовам, подподвызовам, чтоб понять проблему.

Простейший отчет
cat /tmp/cpu_report | grep  'RIP: ' | sort -k 5,5 | uniq -c -f 4 | sort -k 1,1n
потом смотрим кто в топе и его колтрейс

Другие способы профилирования

Callgrind gprof crxprof systemtap

Самый простой способ без установки тулз:
strace -c -p 14308
Далее зажимаем enter
По колво пустого места между строк видно какой сискол тупил

Как найти строчку кода

Можно узнать конкретные команды и строчки через 
gdb vmlinux
> disass *0xfffffffff82324523
видим что это net_rx+121
> list *0xfffffffff82324523
> list net_rx+121

Часто узнавать приходится через смещение тк требуется перекомпиляция модуля или подсистемы ядра с -g debug. Часто gdb глючит если весь vmlinux с дебагом и тогда компилим конкретные net.o с дебагом и потом находим через смещение.

gdb net.o
list net_rx+121

Установка и использование oprofile

http://geoe.mu.edu.tr/sharedoc/oprofile-0.9.7/oprofile.html#controlling-daemon

yum install oprofile

Если профилируем ванильное ядро CentOS

Включаем репозиторий

/etc/yum.repos.d/CentOS-Debuginfo
enabled=1

Найти название пакета с нужной версией можно с помощью:

yum --showduplicates list kernel-debuginfo

yum -y install kernel-debuginfo

качаться будет долго, можно попить чаёк или сделать мелкую таску. Не знаю почему пишется centos.plus но оно нам не нужно, так что:

mv  /usr/lib/debug/lib/modules/2.6.32-642.1.1.el6.centos.plus.x86_64/ /usr/lib/debug/lib/modules/2.6.32-642.1.1.el6.x86_64/

тогда можем указывать параметр vmlinux динамически:

/usr/lib/debug/lib/modules/`uname -r`/vmlinux

Если кастомное ядро

Копируем кастомный или хотя бы близкий к нему vmlinux например в /boot/.
Если есть только близкий vmlinux, то точную функцию сможем найти по адресу в /proc/kallsyms (и почему oprofile сам его не использует?)

Использование

echo 0 > /proc/sys/kernel/nmi_watchdog
opcontrol --deinit
opcontrol --init
opcontrol --reset
opcontrol --start --vmlinux=/usr/lib/debug/lib/modules/2.6.32-642.el6.x86_64/vmlinux
# но иногда можно и --no-vmlinux если нам не важно про ядро, а только про юспейс
# если баг Failed to open profile device: Device or resource busy, то стопаем все виртуалки KVM, одна из них залочила nmi
sleep 10 # ждем сбора статистики
opcontrol --stop
 
# включаем watchdog обратно
echo 1 > /proc/sys/kernel/nmi_watchdog
# собрали стату, стопнули, чтоб не грузить.

Отчеты oprofile

Отчет стандартный

отчет по функциям

opreport -l
samples % image name app name symbol name
54308 29.3501 kvm_intel kvm_intel /kvm_intel
14571 7.8747 vmlinux vmlinux intel_idle
13697 7.4024 kvm kvm /kvm
6923 3.7415 vmlinux vmlinux ksm_scan_thread
4437 2.3979 vmlinux vmlinux follow_page
4017 2.1709 vmlinux vmlinux memcmp_pages

отчет по адресам. в тч inline и lock

opreport -d -l
0000000000000000 54308 29.3501 kvm_intel kvm_intel /kvm_intel
0000000000000050 23 0.0424
0000000000000051 10 0.0184
0000000000000058 1 0.0018
000000000000005c 3 0.0055
0000000000000060 2 0.0037

Отчета о кастомном модуле

opreport -l -w -p /lib/modules/2.6.32-642.el6.x86_64/kernel/drivers/net/i40e/
opreport -l -w -p /node/bin 2>&1| head -n 100 | grep flas
0000000000007d30 5385 1.3249 flashcache.ko flashcache flashcache_hash_lookup
0000000000003400 3255 0.8008 flashcache.ko flashcache hash_block
00000000000037b0 1792 0.4409 flashcache.ko flashcache flashcache_setlocks_multiget

~~OWNERAPPROVE~~