mysql = wysokie obciążenie procesora

[Syndrom 95]

Zatrzymałem się w miejscu przy analizie, dlaczego okresowo zużycie procesora dla mysql skacze do 100%, co za tym zużycie procesora dla apacha skacze, ponieważ czeka na odpowiedzi od mysqla.

# free -m
             total       used       free     shared    buffers     cached
Mem:         32071      31891        179          0       1008      29046
-/+ buffers/cache:       1836      30234

4x Intel(R) Xeon(R) CPU E3-1225 V2 @ 3.20GHz

# du -sh /var/lib/mysql/
787M    /var/lib/mysql/

Kiedy CPU skacze dla prcoesu do 100% sprawdzam listę procesów mysqla i nic tam nie ma:

mysql> show full processlist;
+------+----------------+-----------+----------------+---------+------+-------+-----------------------+
| Id   | User           | Host      | db             | Command | Time | State | Info                  |
+------+----------------+-----------+----------------+---------+------+-------+-----------------------+
| 4501 | dofa_0          | localhost | dofa_0         | Sleep   | 3413 |       | NULL                  |
| 1255 | myroot          | localhost | NULL           | Query   |    0 | NULL  | show full processlist |
+------+----------------+-----------+----------------+---------+------+-------+-----------------------+
2 rows in set (0.00 sec)

Mysql jest wystawiony na zewnątrz i może przez próby ataku load skacze ?

 

Jeszcze co pokazuje mysqltunner.pl

-------- Storage Engine Statistics -------------------------------------------
[--] Status: +CSV +InnoDB +MRG_MYISAM 
[--] Data in MyISAM tables: 550M (Tables: 1008)
[--] Data in InnoDB tables: 90M (Tables: 757)
[!!] Total fragmented tables: 758

-------- Security Recommendations  -------------------------------------------
[OK] All database users have passwords assigned

-------- Performance Metrics -------------------------------------------------
[--] Up for: 11h 46m 41s (1B q [23K qps], 5K conn, TX: 165B, RX: 71B)
[--] Reads / Writes: 90% / 10%
[--] Total buffers: 818.0M global + 12.4M per thread (151 max threads)
[OK] Maximum possible memory usage: 2.6G (8% of installed RAM)
[OK] Slow queries: 0% (0/1B)
[OK] Highest usage of available connections: 9% (15/151)
[OK] Key buffer size / total MyISAM indexes: 384.0M/44.3M
[OK] Key buffer hit rate: 99.7% (16M cached / 53K reads)
[OK] Query cache efficiency: 100.0% (508M cached / 508M selects)
[OK] Query cache prunes per day: 0
[OK] Sorts requiring temporary tables: 0% (0 temp sorts / 11K sorts)
[!!] Temporary tables created on disk: 42% (11K on disk / 26K total)
[OK] Thread cache hit rate: 99% (15 created / 5K connections)
[!!] Table cache hit rate: 1% (512 open / 31K opened)
[OK] Open file limit used: 9% (108/1K)
[OK] Table locks acquired immediately: 99% (96K immediate / 96K locks)
[OK] InnoDB buffer pool / data size: 384.0M/90.4M
[!!] InnoDB log waits: 1
-------- Recommendations -----------------------------------------------------
General recommendations:
    Run OPTIMIZE TABLE to defragment tables for better performance
    MySQL started within last 24 hours - recommendations may be inaccurate
    Enable the slow query log to troubleshoot bad queries
    When making adjustments, make tmp_table_size/max_heap_table_size equal
    Reduce your SELECT DISTINCT queries without LIMIT clauses
    Increase table_cache gradually to avoid file descriptor limits
    Read this before increasing table_cache over 64: http://bit.ly/1mi7c4C
Variables to adjust:  
    tmp_table_size (> 16M)
    max_heap_table_size (> 16M)
    table_cache (> 512)
    innodb_log_buffer_size (>= 1M)

Czy mogę liczyć na jakieś wskazówki ? Na co jeszcze zwrócić uwagę ? Acha. IO też jest w porządku podczas obciążenia procka, więc to nie wina dysków...

 

[Gość Kamikadze]

MySQL tuner ci zawsze odpowiada co zmienić:

 

 

-------- Recommendations -----------------------------------------------------
General recommendations:
Run OPTIMIZE TABLE to defragment tables for better performance
MySQL started within last 24 hours - recommendations may be inaccurate
Enable the slow query log to troubleshoot bad queries
When making adjustments, make tmp_table_size/max_heap_table_size equal
Reduce your SELECT DISTINCT queries without LIMIT clauses
Increase table_cache gradually to avoid file descriptor limits
Read this before increasing table_cache over 64: http://bit.ly/1mi7c4C
Variables to adjust:
tmp_table_size (> 16M)
max_heap_table_size (> 16M)
table_cache (> 512)
innodb_log_buffer_size (>= 1M)

 

 

[Syndrom 95]

Jak byś nie zmieniał parametrów tak zawsze mysqltuner inaczej odpowie. Nie można tylko na niego patrzeć

[niepozwole 20]

Na pierwszy rzut oka obstawiłbym to:

Temporary tables created on disk: 42% (11K on disk / 26K total)

Sprawdź co podczas zwiększonego obciążenia konkretnie robi serwer MySQL. Przydatne będzie polecenie: https://dev.mysql.com/doc/refman/5.5/en/show-status.html

 

Być może w tym czasie MySQL tworzy sobie dużą liczbę małych tabel tymczasowych, dlatego nie jesteś w stanie tego wyłapać.

 

Dodatkowo polecam również podczas obciążenia odpalić narzędzie mytop z interwałem czasowym 1s. Zapytania mogą być bardzo szybkie, być może tak uda Ci się je wychwycić.

[Syndrom 95]

Porównałem parametry podczas stabilnej pracy i skoku CPU i za bardzo nie ma różnic. Tak sobie pomyślałem, jeśli to są skoki, to poprostu leci jakieś niezoptymalizowane zapytanie, tym bardziej, że jedna baza danych nie posiada indeksów.

Czy może to być problemem ?

[Misiek08 285]

Może.

[Gość dmho]

Powiem Ci że przesiedziałem trochę nad optymalizacją mysqla i największy wpływ ma brak optymalizacji zapytań/bazy. Możesz próbować przepychać do cache'u co się da (szczególnie że masz sporo wolnego ramu) ale praktycznie zawsze będziesz miał takie skoki.

http://blog.secaserver.com/2011/08/mysql-recommended-my-cnf-settings-innodb-engine/ - to akurat dla innodb, ale może coś podpowie odnośnie ustawień.

 

[malu 460]

Wersja MySQL, skąd ona pochodzi?
Strace podczas wspomnianych skoków zużycia CPU.
Równocześnie z strace podczas skoku próbowałbym wspomnianego mytopa z niskim interwałem wyświetlającego show full processlist.

[elcct 159]

Nawet jeśli w bazie są indeksy, warto sprawdzić czy są używane przez zapytania (komendą EXPLAIN). Czasem MySQL źle wybiera indeksy, które ma użyć do zapytania i trzeba mu podpowiedzieć np. SELECT ... FROM ... USE INDEX (nazwa indeksu)

 

 

[niepozwole 20]

Porównałem parametry podczas stabilnej pracy i skoku CPU i za bardzo nie ma różnic. Tak sobie pomyślałem, jeśli to są skoki, to poprostu leci jakieś niezoptymalizowane zapytanie, tym bardziej, że jedna baza danych nie posiada indeksów.

Czy może to być problemem ?

Jeżeli podejrzewasz problem ze słabą optymalizacją zapytań to polecam włączyć slow query log. Wszystko opisane jest tutaj: https://dev.mysql.com/doc/refman/5.5/en/slow-query-log.html. Do pliku zostaną zrzucone zapytania wolniejsze niż czas jaki ustawisz. Dodatkowo znajdą się tam cenne informacje odnośnie buforów, indeksów itd.

 

Taki plik slow loga polecam również przepuścić przez narzędzie: http://www.percona.com/doc/percona-toolkit/2.2/pt-query-digest.html. Znacznie ułatwia analizę danych oraz robi ładne podsumowania.

 

Jeszcze mała wskazówka: nic nie stoi na przeszkodzie abyś ustawił czas na 0, wtedy zostaną zalogowane wszystkie zapytania. :-)

Edytowano Kwiecień 28, 2014 przez niepozwole (zobacz historię edycji)

[Syndrom 95]

Z strace mam ciągle takie zapytania.

[pid  9202] read(16, "\3SELECT `IDKategorii`, `NazwaKat"..., 118) = 118
[pid  9202] sched_setparam(16, { 1279611651 }) = -1 EINVAL (Invalid argument)
[pid  9202] write(16, "\1\0\0\1\3Z\0\0\2\3def\16dofe_0\20ofe"..., 307) = 307
[pid  9202] sched_setparam(16, { 16777217 }) = -1 EINVAL (Invalid argument)

Slow query log mam włączone i od czasu do czasu lądują tam zapytania jakieś większe:

# Query_time: 8.770168  Lock_time: 0.000114 Rows_sent: 1000  Rows_examined: 64842158
SET timestamp=1398688918;

Ale z strace wynika, że być może jakiś skrypt wisi i wali zapytaniami w koło.

 

/EDIT

Strace dla procesu apacha, który też wtedy skacze na wysokie CPU

rite(121, "v\0\0\0\3SELECT `IDKategorii`, `Nazw"..., 122) = 122
read(121, "\1\0\0\1\3Z\0\0\2\3def\16dofe_0\20ofe"..., 16384) = 307
poll([{fd=121, events=POLLIN|POLLPRI}], 1, 0^C) = 0 (Timeout)

Edytowano Kwiecień 28, 2014 przez Syndrom (zobacz historię edycji)

[niepozwole 20]

# Query_time: 8.770168  Lock_time: 0.000114 Rows_sent: 1000  Rows_examined: 64842158
SET timestamp=1398688918;

W tym wycinku strace nie widać nic niepokojącego (komunikat Timeout jest raczej standardem i powinien spływać dosyć często). Natomiast wpis, który wkleiłeś ze slow loga jest niepokojący: zapytanie zwróciło tylko 1000 rekordów a zostało przeanalizowane 64842158. Zdecydowanie na tej tabeli, z której pochodzi wpis brakuje dobrego indeksu.

[Syndrom 95]

Dobra od dupy strony zacząłem, aż wstyd się przyznać. Założyłem, że to mysql ma jakieś braki i przez to apacha ma duże CPU.

A jest odwrotnie. Duże CPU jest na apachu bo googlebot siedzi i napierdziela. Jak zablokowałem klasę googla jest spokój już długi czas.

 

[niepozwole 20]

Dobra od dupy strony zacząłem, aż wstyd się przyznać. Założyłem, że to mysql ma jakieś braki i przez to apacha ma duże CPU.

A jest odwrotnie. Duże CPU jest na apachu bo googlebot siedzi i napierdziela. Jak zablokowałem klasę googla jest spokój już długi czas.

 

 

To nie zmienia faktu, że w takim wypadku baza mysql jest u Ciebie wąskim gardłem. Warto przyjrzeć się tematowi i nawet jeśli nie chcesz optymalizować to chociaż popracować nad indeksami. To może być ciekawa przygoda. :-)

[Gość squeezer]

Dobra od dupy strony zacząłem, aż wstyd się przyznać. Założyłem, że to mysql ma jakieś braki i przez to apacha ma duże CPU.

A jest odwrotnie. Duże CPU jest na apachu bo googlebot siedzi i napierdziela. Jak zablokowałem klasę googla jest spokój już długi czas.

 

 

Jestem prawie pewny że to jednak Twoja pierwsza diagnoza była poprawna. Po pierwsze, fragment slowloga który wkleiłeś - sprawdzanie 64m rekordów generuje spore obciążenie na CPU i trwa chwilę. Po drugie - sam stwierdziłeś że jedna z baz nie posiada indeksów. Jeśli tylko nie są to tabele z kilkoma rekordami na krzyż, to na pewno stanowi to jakiś problem.

 

Zablokowanie googlebota załatwiło sprawę bo to on był źródłem zapytań, które generowały obciążenie. Google bot ma to do siebie, że "klika" na linki, na które normalnie nikt by w życiu nie wszedł.

 

Nie wiem oczywiście jak to wygląda u Ciebie, ale sztandarowy przykład to jakiegoś rodzaju strona z paginacją. Dajmy na to że mamy 10 milionów wpisów, wyświetlamy po 1000 na stronie.

Pierwsza strona (LIMIT 1000) - MySQL odczyta 1000 i prześle 1000 rekordów. Druga strona (LIMIT 1000, 1000) - MySQL odczyta 2000 i prześle ostatnie 1000 rekordów. Tysięczna strona (LIMIT 999000, 1000) - MySQL odczyta milion rekordów i prześle ostatnie 1000.

Normalny użytkownik raczej nie będzie szukać niczego tysiące podstron temu. Google bot - jak najbardziej.

 

Dane ze slowloga (niestety nie przekopiowałeś zapytania - prawdopodobnie było linię, dwie poniżej SET TIMESTAMP) przypominają mi na oko jeszcze jeden typowy problem z LIMIT. Często chcemy żeby paginacja zrobiona była według jakiegoś porządku - czy to my narzucamy kolejność wpisów czy też zostawiamy użytkownikowi możliwość wyboru kilku opcji sortowania.

Zazwyczaj zrobione jest to przez SELECT * FROM tabela ORDER BY kolumna_do_sortowania LIMIT 1000 (i tak dalej). U sporej ilości osób widuję przekonanie że LIMIT cokolwiek limituje. Niestety, nie. W poprzednim przykładzie problem zwiększał się wraz z kolejnymi podstronami. W przypadku tego typy zapytania - z sortowaniem - sprawa jest jeszcze gorsza. MySQL _najpierw_ przesortuje _całą_ tabelę (nawet i z milionami rekordów, jeśli tyle danych w niej zostało umieszczone) po kolumnie kolumna_do_sortowania a potem prześle pierwszych 1000 rekordów dalej.

 

LIMIT faktycznie zaczyna coś limitować (w niektórych przypadkach) począwszy od MySQL 5.6. Dla wszystkich wcześniejszych wersji jest to głównie ładny sposób na ograniczenie ilości rekordów _przekazanych_ do klienta, ale nie odczytanych po stronie MySQL - paginację, jeśli ma się skalować, trzeba rozwiązać w inny sposób.

[peres.pro 9]

Dodatkowo polecałbym memcached.

[LANcaster (kotkowicz.pl) 52]

Zazwyczaj zrobione jest to przez SELECT * FROM tabela ORDER BY kolumna_do_sortowania LIMIT 1000 (i tak dalej). U sporej ilości osób widuję przekonanie że LIMIT cokolwiek limituje. Niestety, nie. W poprzednim przykładzie problem zwiększał się wraz z kolejnymi podstronami. W przypadku tego typy zapytania - z sortowaniem - sprawa jest jeszcze gorsza. MySQL _najpierw_ przesortuje _całą_ tabelę (nawet i z milionami rekordów, jeśli tyle danych w niej zostało umieszczone) po kolumnie kolumna_do_sortowania a potem prześle pierwszych 1000 rekordów dalej.

 

LIMIT faktycznie zaczyna coś limitować (w niektórych przypadkach) począwszy od MySQL 5.6. Dla wszystkich wcześniejszych wersji jest to głównie ładny sposób na ograniczenie ilości rekordów _przekazanych_ do klienta, ale nie odczytanych po stronie MySQL - paginację, jeśli ma się skalować, trzeba rozwiązać w inny sposób.

 

Trochę bzdurzysz. O ile jest indeks na kolumnę do której stosujemy ORDER BY, MySQL nie będzie musiał skanować całego datasetu, by potem przekazać część wyników określonych klauzulą LIMIT. Skończy po prostu po tylu wynikach, na ile miał ustawiony limit (dlatego też tak ważne jest ustawianie poprawnych indeksów).

 

Tak samo nie ma znaczenia tutaj wersja MySQL - w wersji 5.6 jeśli nie ma indeksu, to i tak MySQL będzie musiał przesortować cały dataset, żeby móc określić jego porządek - a dopiero potem wysłać odpowiednią porcję wyników do klienta.

 

Polecam lekturę: http://www.mysqlperformanceblog.com/2006/09/01/order-by-limit-performance-optimization/

 

(Post z 2006 roku, grubo przed MySQL 5.6)