Dziś będzie o bugu, na którego ostatnio się natknąłem. Mam nadzieję, że komuś, kiedyś przyda się ten post. Szczególnie, że MySQL z linii 5.5 coraz częściej pojawia się na serwerach, a błąd ten właśnie z tą wersją jest związany. Objawy są dosyć standardowe – mysqld po prostu nie wstaje. Co widzimy w logach:

Nov xx yy:yy:yy mysqlserv mysqld: 111117 yy:yy:yy [Note] Flashcache bypass: disabled
Nov xx yy:yy:yy mysqlserv mysqld: 111117 yy:yy:yy [Note] Flashcache setup error is : ioctl failed
Nov xx yy:yy:yy mysqlserv mysqld:
Nov xx yy:yy:yy mysqlserv mysqld: 111117 yy:yy:yy [Note] Plugin 'FEDERATED' is disabled.
Nov xx yy:yy:yy mysqlserv mysqld: 111117 yy:yy:yy InnoDB: The InnoDB memory heap is disabled
Nov xx yy:yy:yy mysqlserv mysqld: 111117 yy:yy:yy InnoDB: Mutexes and rw_locks use GCC atomic builtins
Nov xx yy:yy:yy mysqlserv mysqld: 111117 yy:yy:yy InnoDB: Compressed tables use zlib 1.2.3.3
Nov xx yy:yy:yy mysqlserv mysqld: 111117 yy:yy:yy InnoDB: Using Linux native AIO
Nov xx yy:yy:yy mysqlserv mysqld: 111117 yy:yy:yy  InnoDB: Warning: io_setup() failed with EAGAIN. Will make 5 attempts before giving up.
Nov xx yy:yy:yy mysqlserv mysqld: InnoDB: Warning: io_setup() attempt 1 failed.
Nov xx yy:yy:yy mysqlserv mysqld: InnoDB: Warning: io_setup() attempt 2 failed.
Nov xx yy:yy:yy mysqlserv mysqld: InnoDB: Warning: io_setup() attempt 3 failed.
Nov xx yy:yy:yy mysqlserv mysqld: InnoDB: Warning: io_setup() attempt 4 failed.
Nov xx yy:yy:yy mysqlserv mysqld: InnoDB: Warning: io_setup() attempt 5 failed.
Nov xx yy:yy:yy mysqlserv mysqld: 111117 yy:yy:yy  InnoDB: Error: io_setup() failed with EAGAIN after 5 attempts.
Nov xx yy:yy:yy mysqlserv mysqld: InnoDB: You can disable Linux Native AIO by setting innodb_native_aio = off in my.cnf
Nov xx yy:yy:yy mysqlserv mysqld: 111117 yy:yy:yy InnoDB: Initializing buffer pool, size = 512.0M
Nov xx yy:yy:yy mysqlserv mysqld: 111117 yy:yy:yy InnoDB: Completed initialization of buffer pool
Nov xx yy:yy:yy mysqlserv mysqld: 111117 yy:yy:yy - mysqld got signal 11 ;

Jak widać, oops. Dalej leci standardowy zrzut informacji, który MySQL załącza w takich przypadkach – i zresztą bardzo dobrze. Informacja ta nie raz przydała mi się żeby zlokalizować przyczynę problemów.

W tym wypadku bardziej przydatny jest komunikat InnoDB o problemach z wykonaniem funkcji io_setup(). Idąc tym tropem trafiamy na buga #61575. Tu mamy wyjaśnienie o co chodzi.

Chodzi o to, że InnoDB w MySQL 5.5 korzysta z asynchronicznego I/O (AIO). Do tej pory takie operacje możliwe były tylko pod Windows, od 5.5 jest tak także w przypadku Linuksa. Ogólna idea asynchronicznego I/O jest taka, że aplikacja nie musi czekać na potwierdzenie wykonania operacji dyskowej. Standardowo, proces, który odwołuje się do dysku, musi czekać aż operacja dyskowa zostanie zrealizowana. To oczywiście trwa. W pewnych sytuacjach jest to niezbędne, bo może zostać uszkodzona integralność danych. W innych jest to niepotrzebne opóźnienie. W takich sytuacjach, do których należy np. wgrywanie danych z dysku do buffer pool – danych, co do których istnieje podejrzenie, że mogą być w przyszłości potrzebne (taki readahead realizowany przez InnoDB), AIO pozwala przyspieszyć działanie przez to, że po wywołaniu żądania odczytania danych z dysku, proces przechodzi od razu do dalszych zadań. Nie czeka na dostęp do dysku.

Linux limituje ilość jednoczesnych, asynchronicznych wywołań. Wysokość tego limitu można sprawdzić w pliku:

cat /proc/sys/fs/aio-max-nr
65536

Domyślnie jest to właśnie 64K. Taki limit w większości wypadków jest wystarczający. Jeśli jednak na danym serwerze mamy sporą ilość serwerów MySQL w wersji 5.5 z danymi w InnoDB, bądź też serwerów wiele nie ma, ale generują one duży ruch na dysku, może się okazać że limit ten jest za mały. Tym bardziej, że MySQL podczas startu InnoDB nie sprawdza jakie limity są ustalone w systemie operacyjnym, tylko odgórnie ustala sobie limit ilości jednoczesnych asynchronicznych wywołań.

Rozwiązaniem problemu było podbicie limitu przy pomocy komendy sysctl, oraz zapisanie tych zmian na stałe.