Всем привет! Данная заметка касается одного практического приёма, который я использовал при решении задачи определения места в ядре ОС Linux, где удерживается определённая спин-блокировка (спин-лок). Данная проблема возникла достаточно спонтанно и, учитывая сложность ядра, могла бы потребовать большое количество времени для решения. Если Вам это интересно, прошу читать далее...
Итак, вот реальная ситуация, которая возникла в проекте Tempesta FW, где мне пришлось принимать участие в роли разработчика ядерного WEB-аккселератора/файервола (да-да, реализованного в ядре Linux).
В ходе работы модуля было замечено, что иногда при нагрузке в логе ядра появляются отладочные сообщения, свидетельствующие о том, что осуществляется попытка выполнения блока кода, предполагающего, что обрабатываемый в нём объект (сокет) не будет удерживаться никем иным.
Благодаря высокой культуре кодирования в проекте, а именно обильному использованию конструкций типа BUG_ON/WARN_ON
и иных всевозможных assert-ов, ситуации, когда что-то пошло в разрез с логикой, реализуемой разработчиком, отлавливались достаточно просто. Так и в этот раз — обладая знанием о внутренней логике работы ядра, разработчик посчитал необходимым обезопасить себя и других и на всякий случай добавил проверку вида:
if (unlikely(spin_is_locked(&sk->sk_lock.slock)))
SS_WARN("Socket is used by two cpus, action=%d"
" state=%d sk_cpu=%d curr_cpu=%d\n",
sw.action, sk->sk_state,
sk->sk_incoming_cpu, smp_processor_id());
И всё было хорошо, пока в логе ядра действительно не стали появляться сообщения "Socket is used by two cpus, ..."
. То есть, в данном месте срабатывало условие if (unlikely(spin_is_locked(&sk->sk_lock.slock))) { ... }
, что являлось свидетельством факта удержания блокировки кем-то ещё. Далее, я расскажу каким образом мне удалось достаточно легко выяснить кто же удерживает данный спин-лок.
Итак, имеем следующее. Есть структура-описатель сокета struct sock
, в которой есть блокировка sk_lock
типа socket_lock_t
, включающая в себя спин-блокировку slock
типа spinlock_t
(см. сюда и сюда). Сам же спин-лок основан на структуре raw_spinlock_t
, включающей в себя карту dep_map
типа struct lockdep_map
, содержащую (в том числе) информацию о холдерах. Последняя, становится доступной только при сборке ядра с опцией CONFIG_DEBUG_LOCK_ALLOC
. Но мы же хакеры :)
Таким образом, для отладки мне потребовалось собрать ядро с опцией CONFIG_DEBUG_LOCK_ALLOC
и внести следующее изменение в код:
--- a/tempesta_fw/sock.c
+++ b/tempesta_fw/sock.c
@@ -1101,11 +1101,14 @@ ss_tx_action(void)
while (!tfw_wq_pop(this_cpu_ptr(&si_wq), &sw)) {
struct sock *sk = sw.sk;
- if (unlikely(spin_is_locked(&sk->sk_lock.slock)))
+ if (unlikely(spin_is_locked(&sk->sk_lock.slock))) {
SS_WARN("Socket is used by two cpus, action=%d"
" state=%d sk_cpu=%d curr_cpu=%d\n",
sw.action, sk->sk_state,
sk->sk_incoming_cpu, smp_processor_id());
+ printk("raw_spinlock = %p\n", &sk->sk_lock.slock.rlock);
+ BUG();
+ }
bh_lock_sock(sk);
switch (sw.action) {
Смысл изменения в том, чтобы при возникновении нужной ситуации сдампить адрес захваченного спинлока в лог и аварийно завершить работу ядра по причине BUG
. В действительности, это даёт отличную возможность сдампить образ ядра по состоянию на момент ошибки и, зная адрес объекта, исследовать его содержимое позже.
Для захвата дампа использовалась связка QEMU + kdump. Последний является механизмом ядра, позволяющим остановить текущее ядро и через kexec загрузить резервное (более простое), которое и сдампит образ предыдущего в виде файла.
Для анализа полученного дампа использовалась утилита crash. Её лучше выкачивать и собирать вручную, т.к. у меня были проблемы со штатными версиями в составе дистрибутивов. Имеем следующее:
crash> log
[ 56.934038] [sync_sockets] Warning: Socket is used by two cpus, action=0 state=1 sk_cpu=2 curr_cpu=2
[ 56.934066] raw_spinlock = ffff880001f28b70
Отлично, адрес объекта известен (ffff880001f28b70
). Посмотрим что там:
crash> raw_spinlock_t ffff880001f28b70
struct raw_spinlock_t {
raw_lock = {
{
head_tail = 0x3434,
tickets = {
head = 0x34,
tail = 0x34
}
}
},
magic = 0xdead4ead,
owner_cpu = 0xffffffff,
owner = 0xffffffffffffffff,
dep_map = {
key = 0xffffffff82cd95f0 <af_family_slock_keys+16>,
class_cache = {0xffffffff8261be30 <lock_classes+319920>, 0xffffffff826283d0 <lock_classes+370512>},
name = 0xffffffff815b719d "slock-AF_INET",
cpu = 0x1,
ip = 0xffffffff813c667f
}
}
По адресу ip = 0xffffffff813c667f
находим функцию, в которой была захвачена блокировка:
$ addr2line -f -e vmlinux 0xffffffff813c667f
tcp_tasklet_func
/home/milabs/linux-stable-4.1/net/ipv4/tcp_output.c:773
Вот и ответ — блокировка на сокете была захвачена в функии tcp_tasklet_func
.
Комментарии (12)
robert_ayrapetyan
06.02.2017 22:52А в чем собственно суть ошибки? Почему сокет не должен был быть захвачен в tcp_tasklet_func и как это пофиксить, если это баг в ядре?
milabs
07.02.2017 02:07Конкретно в том случае проблема была в том, что нарушалась локальность обработки данных. Сокет, а вместе с ним и сетевое соединение, обслуживалось разными CPU. С точки зрения производительности на SMP-системах это плохой вариант, т.к. страдают кеши, возникают кросс-блокировки между ядрами.
win32asm
07.02.2017 06:03Хм. А по списку «живых» процессов не было очевидно, кто зохавал спинлок? Или соответствующий процесс забирал спинлок и забывал отдать?
Могу поделиться «фильтром процессов» для крэша — оно выкидывает спящие и консольные процессы, и объединяет одинаковые стектрейсы.milabs
07.02.2017 11:33Не совсем понял как анализ процессов может помочь. Сеть в soft-IRQ работает, это ядерный контекст, там понятия current-процесса не существует.
По поводу фильтра — делитесь, конечно.win32asm
07.02.2017 13:07Мнда, мне ещё копать и копать ядро — про тасклеты читал, но вспомнил только сейчас. Пошел перечитывать https://habrahabr.ru/company/embox/blog/244071/ 8-\
Я исходил из предположения, что спинлок должен быстро отдаваться, а если он не отдаётся быстро — то в стеке одного из «рабочих тредов/тасков» будет функция, которая и забрала спинлок. Ну и если в этот момент сделать BUG(), то при анализе работающих процессов должно быть очевидно, кто этот спинлок держит.
Скрипт тут: https://gist.github.com/win32asm/96dca779362bbd04a1730b109e452fce
Мне очень помогает при дебаге ядерного модуля. 8-)milabs
07.02.2017 14:39то в стеке одного из «рабочих тредов/тасков» будет функция, которая и забрала спинлок
Нет, это не верно. Спинлок в упрощённом варианте это что-то типа lock=1 для захвата и lock=0 для освобождения. То есть захват/освобождение — это просто смена состояний объекта. Соответствующие функции скорее-всего inline, поэтому следов в стеке они не оставляют, да и анализ стека выше стекового указателя — это не правильно, там будет мусор.
win32asm
07.02.2017 15:07ну да, вызовов собственно spin_lock*() в трейсах не будет, но сам спинлок будет «кривой» (верхнее слово не равно нижнему), и обычно (иногда?) по «верхней» функции в трейсе можно догадаться, не могла ли именно эта фн его забрать.
Если работа со спинлоком «разнесена», как в iget_locked() / unlock_new_inode(), то приходится смотреть ещё на пару уровней «в ширину». Но КМК хорошим стилем является отпускать спинлок в той же фн, где он взят.milabs
07.02.2017 15:29Не, ну трейсы безусловно помогают. Иногда достаточно сделать
WARN_ON(1)
чтобы понять что происходит :)
mkevac
11.02.2017 14:01Расскажите, пожалуйста, как вы программируете и дебажите ядро поподробнее. Вся разработка идет через QEMU или с реальным железом тоже?
milabs
11.02.2017 19:11QEMU позволяет безболезненно ронять систему по много раз + собирать креш-дампы. В остальном — основной метод это отладочная печать через
printk
… Несколько раз пользовалсяkgdb
, но он нужен в редких случаях, даже сейчас сходу не скажу в каких :)
afiskon
Спасибо, весьма познавательно. Пожалуйста, пишите еще статей о ядре Linux. Материалов решительно не хватает!