“The futex facility returned an unexpected error code.” – losowy błąd podczas uruchamiania programu

0

Co robię:
Uruchamiam program serwer https://github.com/overcq/oux-web-srvovercq/oux-web-srv) korzystający z biblioteki oux.
Losowo przy pewnych uruchomieniach glibc wraca z błędem “The futex facility returned an unexpected error code.” i kończy działanie programu.
Jeśli to w czymś pomoże, to w programie wykorzystuję wielowątkowość i właśnie w nowo utworzonym wątku występuje ten błąd.

Co znalazłem dotychczas:
Komunikat wypisywany jest przez glibc https://github.com/bminor/glibc/blob/master/sysdeps/nptl/futex-internal.h#L143 . Po sprawdzeniu błędem, z którym wraca lll_futex_timed_wait, jest -EINVAL.
W kernelu błąd powstaje w https://elixir.bootlin.com/linux/v5.16.12/source/kernel/futex/waitwake.c#L143 . Jest generowany przez get_futex_key z linii 154.

Co próbowałem robić:
Usunąłem wywołanie epoll_wait z https://github.com/overcq/oux-web-srv/blob/master/srv.cx#L412 .
Zmieniłem wyrównanie thread_flow_mutex z https://github.com/overcq/oux/blob/master/module/base/flow-drv.cx#L300 do 128 bajtów.
Dalej losowo występuje ten błąd.

Co w wyszukiwarce:
Wiele zgłoszeń o tym błędzie, ale niemożliwość jego odtworzenia. Jedynym sensownym opisem wydaje się https://refi64.com/posts/chromium-audio-break.html , ale to raczej nie dotyczy tego problemu i nie da się zobaczyć, co zostało zmienione w kernelu bądź glibc, ponieważ nie wiem, od kiedy występuje ten błąd.

Dziękuję za wszelką pomoc w rozwiązaniu problemu.

2

Internet podpowiada, że ten błąd może wystąpić jeśli wskaźnik na futex jest nieprawidłowy (np. zostaje w którymś miejscu nadpisany losową liczbą) - na Twoim miejscu spróbowałbym odpalić program pod debuggerem i zobaczył czy wartość wskaźnika w momencie jego użycia zgadza się z wartością z momentu utworzenia (a jeśli nie, no to - w terminologii GDB - zakładasz watchpoint i patrzysz co go nadpisuje).

0

Nie używam bezpośrednio futex w kodzie, ale używam pthread_mutex.
I zauważyłem dziwne zachowanie glibc: mimo że wywołuję pthread_mutex_lock, to zmienna typu pthread_mutex_t jest modyfikowana dopiero po pewnym czasie, po wykonaniu kolejnych instrukcji programu. Poniżej przykład z gdb. Źródła są tutaj i tutaj.

W głównym wątku tworzę mutex i nowy wątek. Oba wątki wykonują pthread_mutex_lock z użyciem pomocniczej zmiennej task->thread_switch_back, by program startowy nowego wątku wykonał się przed kontynuacją głównego wątku.
I jak raportuje gdb, *task->thread_flow_mutex jest zmieniane po wywołaniu pthread_mutex_lock( task->thread_flow_mutex ) w 2. wątku dopiero po przełączeniu do 1. wątku i powrocie do tegoż 2. wątku. Jest zmieniane z 0 na 1, co jest oczywiste. Natomiast za chwilę po wywołaniu już linię wcześniej pthread_mutex_lock( thread_flow_mutex ) w 1. wątku dopiero po przełączeniu do 2. wątku i powrocie do 1. wątku *task->thread_flow_mutex jest zmieniane z 1 na 2.
Tak jakby wątek nie powinien się zablokować na pthread_mutex_lock w którymkolwiek z tych wątków.
Wtedy z opóźnieniem przychodzi ten błąd o nieprawidłowym argumencie dla futex.

Co robię nie tak przy obsłudze mutex? Zaznaczam, że ileś wersji wstecz kernela i glibc wszystko działało bez problemu.
Jeśli to jest błąd w obsłudze mutex przez glibc, to nie dziwię się, że trudno go było odtworzyć, skoro wszystko zależało od czasu przełączenia wątków na początku po lock.

Breakpoint 1, E_flow_Q_task_M (uid=<optimized out>, task_proc=<optimized out>, thread_proc_arg=<optimized out>, task_in_thread_kind=<optimized out>, task_proc_name=<optimized out>) at ../../module/base/flow-drv.c:428
428	        Vr( pthread_create( &task->thread, &thread_attr, E_flow_Q_task_in_thread_I_thread_proc, &task_proc_args ))
(gdb) c
Continuing.
[New Thread 0x7ffef3142640 (LWP 17496)]
[Switching to Thread 0x7ffef3142640 (LWP 17496)]

Thread 2 "srv_D_srv" hit Breakpoint 4, E_flow_Q_task_in_thread_I_thread_proc (args_=0x7fffffffd9c8) at ../../module/base/flow-drv.c:579
579	    Vr( pthread_mutex_lock( task->thread_flow_mutex ))
(gdb) x task->thread_flow_mutex 
0x7ffff7fc4ac9:	0x00000000
(gdb) watch -l *0x7ffff7fc4ac9
Hardware watchpoint 10: -location *0x7ffff7fc4ac9
(gdb) c
Continuing.
[Switching to Thread 0x7ffff792d740 (LWP 17495)]

Thread 1 "a.out" hit Breakpoint 2, E_flow_Q_task_M (uid=<optimized out>, task_proc=<optimized out>, thread_proc_arg=<optimized out>, task_in_thread_kind=<optimized out>, task_proc_name=<optimized out>) at ../../module/base/flow-drv.c:471
471	        O{  V0_( sched_yield() );
(gdb) c
Continuing.

Thread 1 "a.out" hit Breakpoint 3, E_flow_Q_task_M (uid=<optimized out>, task_proc=<optimized out>, thread_proc_arg=<optimized out>, task_in_thread_kind=<optimized out>, task_proc_name=<optimized out>) at ../../module/base/flow-drv.c:472
472	            Vr_( pthread_mutex_lock( thread_flow_mutex ));
(gdb) c
Continuing.
[Switching to Thread 0x7ffef3142640 (LWP 17496)]

Thread 2 "srv_D_srv" hit Hardware watchpoint 10: -location *0x7ffff7fc4ac9

Old value = 0
New value = 1
0x00007ffff7d54cef in pthread_mutex_lock () from /lib64/libc.so.6
(gdb) c
Continuing.

Thread 2 "srv_D_srv" hit Breakpoint 5, E_flow_Q_task_in_thread_I_thread_proc (args_=0x7fffffffd9c8) at ../../module/base/flow-drv.c:584
584	    V0( sigaltstack( &args->alt_stack, 0 ))
(gdb) c
Continuing.
[Switching to Thread 0x7ffff792d740 (LWP 17495)]

Thread 1 "a.out" hit Hardware watchpoint 10: -location *0x7ffff7fc4ac9

Old value = 1
New value = 2
0x00007ffff7d4e8a1 in ?? () from /lib64/libc.so.6
(gdb) c
Continuing.
The futex facility returned an unexpected error code.
[Switching to Thread 0x7ffef3142640 (LWP 17496)]

Thread 2 "srv_D_srv" hit Breakpoint 6, E_flow_Q_task_in_thread_I_thread_proc (args_=0x7fffffffd9c8) at ../../module/base/flow-drv.c:589
589	    args->proc( task->thread_proc_arg );
(gdb) c
Continuing.

Thread 1 "a.out" received signal SIGABRT, Aborted.
[Switching to Thread 0x7ffff792d740 (LWP 17495)]
0x00007ffff7d5372c in ?? () from /lib64/libc.so.6
1

Ciężko się czyta ten kod OUX... Może fałszywy trop, ale... https://elixir.bootlin.com/linux/v5.16.12/source/kernel/futex/core.c#L237 wymaga by adres futexa był "naturalny" (względem rozmiaru strony pamięci). Jeśli tak nie jest, to leci właśnie -EINVAL.

To OUX wydaje się mieć potencjał do przesuwania danych w pamięci na różne sposoby -> https://github.com/overcq/oux/blob/master/module/base/mem-blk.cx
Może gdzieś te dane się przesuwają, w efekcie adres, na którym zapinasz pthread_mutex_locka przestaje spełniać warunki oczekiwane przez kernel.

1
yarel napisał(a):

Ciężko się czyta ten kod OUX... Może fałszywy trop, ale... https://elixir.bootlin.com/linux/v5.16.12/source/kernel/futex/core.c#L237 wymaga by adres futexa był "naturalny" (względem rozmiaru strony pamięci). Jeśli tak nie jest, to leci właśnie -EINVAL.

Słuszna uwaga.

To OUX wydaje się mieć potencjał do przesuwania danych w pamięci na różne sposoby -> https://github.com/overcq/oux/blob/master/module/base/mem-blk.cx
Może gdzieś te dane się przesuwają, w efekcie adres, na którym zapinasz pthread_mutex_locka przestaje spełniać warunki oczekiwane przez kernel.

Przesuwa, ale trzeba zażądać zmiany, więc tutaj nie przesuwa. Tylko tutaj był błąd od początku: miał przydzielić wyrównany adres, a przydzielał niewyrównany. Już poprawiłem (błąd ze skopiowania funkcji w mem-blk.cx i nie dostosowania do potrzeb).
Poza tym dzięki za wskazanie, do jakiej wartości trzeba wyrównywać (sizeof(u32)), bo poprzednio wpisałem, że do aż 16 bajtów.

Teraz ponownie działa bez błędów. Dzięki.

1 użytkowników online, w tym zalogowanych: 0, gości: 1