Debugowanie deadlocków z gdb

linux, , , ,

 
W programowaniu wielowątkowym zdarza się bardzo wiele problemów, wynikających z tego, że program wykonuje się współbieżnie w wielu wątkach naraz i niestety istnieje potrzeba dostępu do współdzielonych zasobów oraz sygnalizacji pewnych zdarzeń. Deadlockami straszą rozmaite podręczniki o programowaniu a za nimi wykładowcy zajęć z programowania wielowątkowego czy systemów operacyjnych. Zupełnie niepotrzebnie, bo w programowaniu wielowątkowym dużo poważniejsze problemy powodują rozmaite wyścigi, jeśli programista zapomniał o umieszczeniu gdzieś sekcji krytycznej, albo tzw. lockouty, wynikające często z braku (lub błędu) sygnalizacji, a na deser pozostają problemy powstałe przez nieodpowiedzialne pląsanie po stercie procesu, współdzielonej przecież przez wszystkie wątki, czyli heap corruption. Deadlock w katalogu wszystkich bugów wydaje się najmniejszym zmartwieniem. Tutaj z reguły wystarczającym rozwiązaniem jest uruchomienie debuggera i skorzystanie z oczu.

Kod źródłowy

Tak, kod źródłowy tym razem na początku. Prosty main(), uruchamiający 5 wątków. Przy czym jeden, ten ostatni, zapomina zwolnić mutexa (jest tą przysłowiową czarną owcą). W bibliotece pthread mutex domyślnie jest nierekurencyjny, czyli jeden wątek nie może zająć tego samego mutexa wielokrotnie bez uprzedniego zwolnienia, chociaż można, przez ustawienie flagi PTHREAD_MUTEX_RECURSIVE wymusić takie zachowanie . W windowsie z tego co pamiętam mutexy są rekurencyjne i basta (trzeba w zamian użyć semafora z ograniczeniem do 1).

#include <cstdio>
#include <pthread.h>
#include <unistd.h>

static const unsigned NUM_THREADS = 5;

struct SThreadConfig {
    unsigned id;
    unsigned sleepInterval;
    bool blackSheep;
};

pthread_t       threads[NUM_THREADS];
SThreadConfig   threadConfigs[NUM_THREADS];

pthread_mutex_t  mutex = PTHREAD_MUTEX_INITIALIZER;

void * threadFn(void * arg)
{
    SThreadConfig* cfg = (SThreadConfig*) arg;
    while (1) {
        sleep(cfg->sleepInterval);
        // The critical section
        pthread_mutex_lock(&mutex);
        printf("Thread #%d woke up\n", cfg->id);
        if (!cfg->blackSheep) // The deadlocking black sheep thread
            pthread_mutex_unlock(&mutex);
    }

}

int main()
{
    for (unsigned ii = 0; ii < NUM_THREADS; ++ii) {
        threadConfigs[ii].id = ii;
        threadConfigs[ii].sleepInterval = ii + 1;
        threadConfigs[ii].blackSheep = (ii == NUM_THREADS - 1); // Last thread is the black sheep

        // Start the thread
		pthread_create(&threads[ii], NULL, threadFn, (void *)&threadConfigs[ii]);
		printf("Started thread #%d\n", threadConfigs[ii].id);
    }
    while (1)
        sleep(1000);
}

No i katastrofa gotowa. Program wykonuje się następująco:

x@y:~$ bin/Debug/deadlocks 
Started thread #0
Started thread #1
Started thread #2
Started thread #3
Started thread #4
Thread #0 woke up
Thread #1 woke up
Thread #0 woke up
Thread #2 woke up
Thread #0 woke up
Thread #3 woke up
Thread #1 woke up
Thread #0 woke up
Thread #4 woke up
(... wisi ...)
^C

 Weźmisz gdb

Tak, gdb, jeśli ktoś z was jeszcze nie korzystał, to jest to dobry moment, żeby zacząć.

x@y:~$ gdb bin/Debug/deadlocks 
GNU gdb (Ubuntu 7.7-0ubuntu3) 7.7
Copyright (C) 2014 Free Software Foundation, Inc.
License GPLv3+: GNU GPL version 3 or later <http://gnu.org/licenses/gpl.html>
This is free software: you are free to change and redistribute it.
There is NO WARRANTY, to the extent permitted by law.  Type "show copying"
and "show warranty" for details.
This GDB was configured as "x86_64-linux-gnu".
Type "show configuration" for configuration details.
For bug reporting instructions, please see:
<http://www.gnu.org/software/gdb/bugs/>.
Find the GDB manual and other documentation resources online at:
<http://www.gnu.org/software/gdb/documentation/>.
For help, type "help".
Type "apropos word" to search for commands related to "word"...
Reading symbols from bin/Debug/deadlocks...done.
(gdb) run

Teraz czekamy na deadlock.

Starting program: ~/bin/Debug/deadlocks 
[Thread debugging using libthread_db enabled]
Using host libthread_db library "/lib/x86_64-linux-gnu/libthread_db.so.1".
[New Thread 0x7ffff77f5700 (LWP 26766)]
Started thread #0
[New Thread 0x7ffff6ff4700 (LWP 26767)]
Started thread #1
[New Thread 0x7ffff67f3700 (LWP 26768)]
Started thread #2
[New Thread 0x7ffff5ff2700 (LWP 26769)]
Started thread #3
[New Thread 0x7ffff57f1700 (LWP 26770)]
Started thread #4
Thread #0 woke up
Thread #0 woke up
Thread #1 woke up
Thread #0 woke up
Thread #2 woke up
Thread #0 woke up
Thread #1 woke up
Thread #3 woke up
Thread #0 woke up
Thread #4 woke up

Już, to teraz trzeba przerwać wykonanie (Ctrl+C) i przyjrzeć się, co się dzieje z naszym programem, a raczej co się nie dzieje.

^C
Program received signal SIGINT, Interrupt.
0x00007ffff78b7d7d in nanosleep () at ../sysdeps/unix/syscall-template.S:81
81	../sysdeps/unix/syscall-template.S: No such file or directory.
(gdb) info threads
  Id   Target Id         Frame 
  6    Thread 0x7ffff57f1700 (LWP 26770) "deadlocks" __lll_lock_wait ()
    at ../nptl/sysdeps/unix/sysv/linux/x86_64/lowlevellock.S:135
  5    Thread 0x7ffff5ff2700 (LWP 26769) "deadlocks" __lll_lock_wait ()
    at ../nptl/sysdeps/unix/sysv/linux/x86_64/lowlevellock.S:135
  4    Thread 0x7ffff67f3700 (LWP 26768) "deadlocks" __lll_lock_wait ()
    at ../nptl/sysdeps/unix/sysv/linux/x86_64/lowlevellock.S:135
  3    Thread 0x7ffff6ff4700 (LWP 26767) "deadlocks" __lll_lock_wait ()
    at ../nptl/sysdeps/unix/sysv/linux/x86_64/lowlevellock.S:135
  2    Thread 0x7ffff77f5700 (LWP 26766) "deadlocks" __lll_lock_wait ()
    at ../nptl/sysdeps/unix/sysv/linux/x86_64/lowlevellock.S:135
* 1    Thread 0x7ffff7fd8740 (LWP 26762) "deadlocks" 0x00007ffff78b7d7d in nanosleep () at ../sysdeps/unix/syscall-template.S:81
(gdb)

info threads wyświetli nam listę wątków, które obecnie istnieją w aplikacji wraz z ich systemowym ID (pthread_t) oraz czubek stosu wywołań, czyli z grubsza to, czym wątek się zajmuje. Wątek główny robi sleep(1000), stąd pojawia się nanosleep(), pozostałe wątki próbują posiąść mutex, stąd __lll_lock_wait(), czekają na zwolnienie mutexa i niestety się nie doczekają. Zatem zajrzyjmy, o który konkretnie mutex chodzi. W tak trywialnym przypadku z góry wiemy, bo jest tylko jeden mutex na całą aplikację, ale „życiowych” przypadkach, gdy mamy wiele, często zbyt wiele mutexów i elementów synchronizacyjnych, nie będziemy z góry wiedzieć, o który konkretnie lock się rozchodzi.

No to od razu z grubej rury, przejrzyjmy stosy *wszystkich* wątków w aplikacji, czasem mogą ich być nawet setki:

(gdb) thread apply all bt

Thread 6 (Thread 0x7ffff57f1700 (LWP 26770)):
#0  __lll_lock_wait ()
    at ../nptl/sysdeps/unix/sysv/linux/x86_64/lowlevellock.S:135
#1  0x00007ffff7bc6657 in _L_lock_909 ()
   from /lib/x86_64-linux-gnu/libpthread.so.0
#2  0x00007ffff7bc6480 in __GI___pthread_mutex_lock (mutex=0x601100 <mutex>)
    at ../nptl/pthread_mutex_lock.c:79
#3  0x0000000000400769 in threadFn (arg=0x6010f0 <threadConfigs+48>)
    at ~/deadlocks/main.cpp:24
#4  0x00007ffff7bc4182 in start_thread (arg=0x7ffff57f1700)
    at pthread_create.c:312
#5  0x00007ffff78f130d in clone ()
    at ../sysdeps/unix/sysv/linux/x86_64/clone.S:111

Thread 5 (Thread 0x7ffff5ff2700 (LWP 26769)):
#0  __lll_lock_wait ()
    at ../nptl/sysdeps/unix/sysv/linux/x86_64/lowlevellock.S:135
#1  0x00007ffff7bc6657 in _L_lock_909 ()
   from /lib/x86_64-linux-gnu/libpthread.so.0
#2  0x00007ffff7bc6480 in __GI___pthread_mutex_lock (mutex=0x601100 <mutex>)
    at ../nptl/pthread_mutex_lock.c:79
#3  0x0000000000400769 in threadFn (arg=0x6010e4 <threadConfigs+36>)
    at ~/deadlocks/main.cpp:24
#4  0x00007ffff7bc4182 in start_thread (arg=0x7ffff5ff2700)
    at pthread_create.c:312
#5  0x00007ffff78f130d in clone ()
    at ../sysdeps/unix/sysv/linux/x86_64/clone.S:111

Thread 4 (Thread 0x7ffff67f3700 (LWP 26768)):
#0  __lll_lock_wait ()
    at ../nptl/sysdeps/unix/sysv/linux/x86_64/lowlevellock.S:135
#1  0x00007ffff7bc6657 in _L_lock_909 ()
   from /lib/x86_64-linux-gnu/libpthread.so.0
#2  0x00007ffff7bc6480 in __GI___pthread_mutex_lock (mutex=0x601100 <mutex>)
    at ../nptl/pthread_mutex_lock.c:79
#3  0x0000000000400769 in threadFn (arg=0x6010d8 <threadConfigs+24>)
    at ~/deadlocks/main.cpp:24
#4  0x00007ffff7bc4182 in start_thread (arg=0x7ffff67f3700)
    at pthread_create.c:312
#5  0x00007ffff78f130d in clone ()
    at ../sysdeps/unix/sysv/linux/x86_64/clone.S:111

Thread 3 (Thread 0x7ffff6ff4700 (LWP 26767)):
#0  __lll_lock_wait ()
    at ../nptl/sysdeps/unix/sysv/linux/x86_64/lowlevellock.S:135
#1  0x00007ffff7bc6657 in _L_lock_909 ()
   from /lib/x86_64-linux-gnu/libpthread.so.0
#2  0x00007ffff7bc6480 in __GI___pthread_mutex_lock (mutex=0x601100 <mutex>)
    at ../nptl/pthread_mutex_lock.c:79
#3  0x0000000000400769 in threadFn (arg=0x6010cc <threadConfigs+12>)
    at ~/deadlocks/main.cpp:24
#4  0x00007ffff7bc4182 in start_thread (arg=0x7ffff6ff4700)
    at pthread_create.c:312
#5  0x00007ffff78f130d in clone ()
    at ../sysdeps/unix/sysv/linux/x86_64/clone.S:111

Thread 2 (Thread 0x7ffff77f5700 (LWP 26766)):
#0  __lll_lock_wait ()
    at ../nptl/sysdeps/unix/sysv/linux/x86_64/lowlevellock.S:135
#1  0x00007ffff7bc6657 in _L_lock_909 ()
   from /lib/x86_64-linux-gnu/libpthread.so.0
#2  0x00007ffff7bc6480 in __GI___pthread_mutex_lock (mutex=0x601100 <mutex>)
    at ../nptl/pthread_mutex_lock.c:79
#3  0x0000000000400769 in threadFn (arg=0x6010c0 <threadConfigs>)
    at ~/deadlocks/main.cpp:24
#4  0x00007ffff7bc4182 in start_thread (arg=0x7ffff77f5700)
    at pthread_create.c:312
#5  0x00007ffff78f130d in clone ()
    at ../sysdeps/unix/sysv/linux/x86_64/clone.S:111

Thread 1 (Thread 0x7ffff7fd8740 (LWP 26762)):
#0  0x00007ffff78b7d7d in nanosleep ()
    at ../sysdeps/unix/syscall-template.S:81
#1  0x00007ffff78b7c14 in __sleep (seconds=0)
    at ../sysdeps/unix/sysv/linux/sleep.c:137
#2  0x0000000000400884 in main () at ~/deadlocks/main.cpp:44
(gdb)

Czasem wygodnie jest zrzucić powyższy log do pliku, by móc go swobodnie analizować, na przykład wtedy, gdy przyłapiemy na deadlocku produkcyjną aplikację, która musi być szybko uruchomiona na nowo.
Interesuje nas znajomo wyglądająca ramka stosu:

#3  0x0000000000400769 in threadFn (arg=0x6010c0 &lt;threadConfigs&gt;)
    at ~/deadlocks/main.cpp:24

Finisz

Tutaj od razu widać, że chodzi o linię 24 z pliku main.cpp, ale niech nam to pokaże gdb. W tym celu trzeba przeskoczyć do obserwowanego wątku, wybrać ramkę i wylistować kod wokół linii 24.

(gdb) thread 2
[Switching to thread 2 (Thread 0x7ffff77f5700 (LWP 26766))]
#0  __lll_lock_wait ()
    at ../nptl/sysdeps/unix/sysv/linux/x86_64/lowlevellock.S:135
135	../nptl/sysdeps/unix/sysv/linux/x86_64/lowlevellock.S: No such file or directory.
(gdb) frame 3
#3  0x0000000000400769 in threadFn (arg=0x6010c0 <threadConfigs>)
    at ~/deadlocks/main.cpp:24
24	        pthread_mutex_lock(&mutex);
(gdb) list
19	{
20	    SThreadConfig* cfg = (SThreadConfig*) arg;
21	    while (1) {
22	        sleep(cfg->sleepInterval);
23	        // The critical section
24	        pthread_mutex_lock(&mutex);
25	        printf("Thread #%d woke up\n", cfg->id);
26	        if (!cfg->blackSheep) // The deadlocking black sheep thread
27	            pthread_mutex_unlock(&mutex);
28	    }
(gdb)

Widać, że chodzi o mutex o nazwie mutex, czyli nasz jedyny mutex, w dodatku z celowym deadlockiem, jednak w „życiowym” przypadku odnajdywanie deadlocków ma szansę być równie proste. Niestety czasem największą przeskodą jest niemożliwość zreprodukowania problemu, ale gdyby się udało, zawsze można z pomocą gdb „podłączyć” się do działającego-niedziałającego procesu przez (gdb) attach <pid> .

Teraz możemy sobie poszperać po przeróżnych zmiennych, wypisać ich wartości, przeglądnąć pamięć, czyli wszystko to, do czego gdb jest niezrównany. Polecam zapoznać się z możliwościami gdb i ściągnąć popularną, jednokartkową, obsutronną ściągawkę do gdb, którą znajdziemy tutaj.

Dodaj komentarz

Twój adres e-mail nie zostanie opublikowany. Wymagane pola są oznaczone *