Заметка о способе отладки блокировок в ядре Linux

Всем привет,

Данная заметка касается одного практического приёма, который я использовал при решении задачи определения места в ядре ОС 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=%dn",
                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=%dn",
                sw.action, sk->sk_state,
                sk->sk_incoming_cpu, smp_processor_id());
+           printk("raw_spinlock = %pn", &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.

Автор: milabs

Источник