Problemy z rozszyfrowaniem impasu w dzienniku stanu innodb

16

Uzyskujemy dostęp do MySQL ze złącza Microsoft ADO.NET.

Czasami widzimy następujący impas w naszym statusie innodb i nie byliśmy w stanie zidentyfikować przyczyny problemu. Wygląda na to, że transakcja (2) czeka i trzyma ten sam zamek?

------------------------
LATEST DETECTED DEADLOCK
------------------------
110606  5:35:09
*** (1) TRANSACTION:
TRANSACTION 0 45321452, ACTIVE 0 sec, OS thread id 3804 starting index read
mysql tables in use 1, locked 1
LOCK WAIT 2 lock struct(s), heap size 368, 1 row lock(s)
    MySQL thread id 84, query id 3265713 localhost 127.0.0.1 famdev Updating
    UPDATE people SET company_id = 1610, name = '<name>', password = '<hash>', temp_password = NULL, reset_password_hash = NULL, email = '<redacted>@yahoo.com', phone = NULL, mobile = '<phone>', iphone_device_id = 'android:<id>-<id>', iphone_device_time = '2011-06-06 05:35:09', last_checkin = '2011-06-06 05:24:42', location_lat = <lat>, location_long = -<lng>, gps_strength = 3296, picture_blob_id = 1190, authority = 1, active = 1, date_created = '2011-04-13 20:21:20', last_login = '2011-06-06 05:35:09', panic_mode = 0, battery_level = NULL, battery_state = NULL WHERE people_id = 3125
    *** (1) WAITING FOR THIS LOCK TO BE GRANTED:
    RECORD LOCKS space id 0 page no 11144 n bits 152 index `PRIMARY` of table `family`.`people` trx id 0 45321452 lock_mode X locks rec but not gap waiting
    Record lock, heap no 12 PHYSICAL RECORD: n_fields 25; compact format; info bits 0
    0: len 8; hex 8000000000000c35; asc        5;; 1: len 6; hex 000002b38ce6; asc       ;; 2: len 7; hex 00000002801f89; asc        ;; 3: len 8; hex 800000000000064a; asc        J;; 4: len 4; hex <data>; asc <name>;; 5: len 30; hex <data>; asc <data>;...(truncated); 6: SQL NULL; 7: SQL NULL; 8: len 16; hex <data>; asc <redacted>@yahoo.com;; 9: SQL NULL; 10: len 10; hex <data>; asc <phone>;; 11: len 30; hex <data>; asc android:<id>;...(truncated); 12: len 8; hex <data>; asc    J]  Z;; 13: len 8; hex <data>; asc    J]  Z;; 14: len 8; hex a39410acaa9b4340; asc       C@;; 15: len 8; hex <data>; asc     m S ;; 16: len 2; hex 8ce0; asc   ;; 17: len 8; hex 80000000000004a6; asc         ;; 18: len 4; hex 80000001; asc     ;; 19: len 1; hex 81; asc  ;; 20: len 8; hex <data>; asc    JR   ;; 21: len 8; hex <data>; asc    J]   ;; 22: len 1; hex 80; asc  ;; 23: SQL NULL; 24: SQL NULL;

    *** (2) TRANSACTION:
    TRANSACTION 0 45321448, ACTIVE 0 sec, OS thread id 3176 starting index read, thread declared inside InnoDB 500
    mysql tables in use 1, locked 1
    5 lock struct(s), heap size 1216, 2 row lock(s), undo log entries 1
    MySQL thread id 85, query id 3265714 localhost 127.0.0.1 famdev Updating
    UPDATE people SET company_id = 1610, name = '<name>', password = '<hash>', temp_password = NULL, reset_password_hash = NULL, email = '<redacted>@yahoo.com', phone = NULL, mobile = '<phone>', iphone_device_id = 'android:<id>-<id>-<id>-<id>', iphone_device_time = '2011-06-06 05:24:42', last_checkin = '2011-06-06 05:35:07', location_lat = <lat>, location_long = -<lng>, gps_strength = 3296, picture_blob_id = 1190, authority = 1, active = 1, date_created = '2011-04-13 20:21:20', last_login = '2011-06-06 05:35:09', panic_mode = 0, battery_level = NULL, battery_state = NULL WHERE people_id = 3125
    *** (2) HOLDS THE LOCK(S):
        RECORD LOCKS space id 0 page no 11144 n bits 152 index `PRIMARY` of table `family`.`people` trx id 0 45321448 lock mode S locks rec but not gap
        Record lock, heap no 12 PHYSICAL RECORD: n_fields 25; compact format; info bits 0
        0: len 8; hex 8000000000000c35; asc        5;; 1: len 6; hex 000002b38ce6; asc       ;; 2: len 7; hex 00000002801f89; asc        ;; 3: len 8; hex 800000000000064a; asc        J;; 4: len 4; hex <data>; asc <name>;; 5: len 30; hex <data>; asc <data>;...(truncated); 6: SQL NULL; 7: SQL NULL; 8: len 16; hex <data>; asc <redacted>@yahoo.com;; 9: SQL NULL; 10: len 10; hex <data>; asc <phone>;; 11: len 30; hex <data>; asc android:<id>;...(truncated); 12: len 8; hex <data>; asc    J]  Z;; 13: len 8; hex <data>; asc    J]  Z;; 14: len 8; hex a39410acaa9b4340; asc       C@;; 15: len 8; hex <data>; asc     m S ;; 16: len 2; hex 8ce0; asc   ;; 17: len 8; hex 80000000000004a6; asc         ;; 18: len 4; hex 80000001; asc     ;; 19: len 1; hex 81; asc  ;; 20: len 8; hex <data>; asc    JR   ;; 21: len 8; hex <data>; asc    J]   ;; 22: len 1; hex 80; asc  ;; 23: SQL NULL; 24: SQL NULL;

        *** (2) WAITING FOR THIS LOCK TO BE GRANTED:
        RECORD LOCKS space id 0 page no 11144 n bits 152 index `PRIMARY` of table `family`.`people` trx id 0 45321448 lock_mode X locks rec but not gap waiting
        Record lock, heap no 12 PHYSICAL RECORD: n_fields 25; compact format; info bits 0
        0: len 8; hex 8000000000000c35; asc        5;; 1: len 6; hex 000002b38ce6; asc       ;; 2: len 7; hex 00000002801f89; asc        ;; 3: len 8; hex 800000000000064a; asc        J;; 4: len 4; hex <data>; asc <name>;; 5: len 30; hex <data>; asc <data>;...(truncated); 6: SQL NULL; 7: SQL NULL; 8: len 16; hex <data>; asc <redacted>@yahoo.com;; 9: SQL NULL; 10: len 10; hex <data>; asc <phone>;; 11: len 30; hex <data>; asc android:<id>;...(truncated); 12: len 8; hex <data>; asc    J]  Z;; 13: len 8; hex <data>; asc    J]  Z;; 14: len 8; hex a39410acaa9b4340; asc       C@;; 15: len 8; hex <data>; asc     m S ;; 16: len 2; hex 8ce0; asc   ;; 17: len 8; hex 80000000000004a6; asc         ;; 18: len 4; hex 80000001; asc     ;; 19: len 1; hex 81; asc  ;; 20: len 8; hex <data>; asc    JR   ;; 21: len 8; hex <data>; asc    J]   ;; 22: len 1; hex 80; asc  ;; 23: SQL NULL; 24: SQL NULL;

        *** WE ROLL BACK TRANSACTION (1)

Czytamy ten artykuł na temat następnego blokowania klucza, ale wydaje się, że nie dotyczy nas, ponieważ nie dokonujemy selekcji do aktualizacji.

Aktualizacja

Dziś rano odkryłem nieco inną sygnaturę zakleszczenia, która może być główną przyczyną tego zakleszczenia. I pisał, że impas w osobnym pytaniu zachować rzeczy proste. Zaktualizuję tutaj, jeśli mogę potwierdzić, że przyczyną jest drugie pytanie.

RedBlueThing
źródło
Zaktualizowałem odpowiedź o większą przepustowość i przepustowość.
RolandoMySQLDBA
Zaktualizowałem swoją odpowiedź,
dodając
BTW Dostajesz +1 za to pytanie, ponieważ ten typ pytania powinien utrzymywać DBA na palcach stóp.
RolandoMySQLDBA

Odpowiedzi:

6

Oto co widzę

Widzę trzy zapytania, wszystkie prawie identyczne.

UPDATE people SET company_id = 1610, name = '<name>', password = '<hash>',
temp_password = NULL, reset_password_hash = NULL, email = '<redacted>@yahoo.com',
phone = NULL, mobile = '<phone>', iphone_device_id = 'android:<id>-<id>',
iphone_device_time = '2011-06-06 05:35:09', last_checkin = '2011-06-06 05:24:42',
location_lat = <lat>, location_long = -<lng>, gps_strength = 3296,
picture_blob_id = 1190,authority = 1, active = 1,
date_created = '2011-04-13 20:21:20',
last_login = '2011-06-06 05:35:09', panic_mode = 0, battery_level = NULL,
battery_state = NULL WHERE people_id = 3125;

Różnice

TRANSAKCJA 1

iphone_device_time = '2011-06-06 05:24:42', last_checkin = '2011-06-06 05:35:07'

TRANSAKCJA 2

iphone_device_time = '2011-06-06 05:35:09', last_checkin = '2011-06-06 05:24:42'

Zauważ, że wartości kolumn są odwrócone. Zwykle impas występuje, gdy dwie różne transakcje uzyskują dostęp do dwóch blokad z dwóch tabel, gdy TX1 (Transakcja 1) otrzymuje wiersz A, a następnie wiersz B, podczas gdy TX2 otrzymuje wiersz B, a następnie wiersz A. W tym przypadku są to TX1 i TX2 dostęp do tego samego wiersza, ale zmiana dwóch różnych kolumn (iphone_device_time, last_checkin).

Wartości nie mają żadnego sensu. O 5:24:42 twoje ostatnie zameldowanie było 5:35:07. Dziesięć minut i 27 sekund później (5:35:07 - 05:24:42) wartości kolumn są odwracane.

Główne pytanie brzmi: dlaczego TX1 utrzymuje się przez prawie 11 minut?

To nie jest tak naprawdę odpowiedź. To tylko przepustowość i ode mnie. Mam nadzieję, że te obserwacje pomogą.

AKTUALIZACJA 2011-06-06 09:57

Proszę sprawdzić ten link dotyczący innodb_locks_unsafe_for_binlog : Powodem, dla którego sugeruję przeczytanie tego, jest coś innego, co widziałem na ekranie STATUS INNODB. Fraza lock_mode X (blokada wyłączna) i lock_mode S (blokada współdzielona) wskazuje, że obie blokady są nałożone (lub próbują narzucić) w tym samym wierszu. Może występować pewna wewnętrzna serializacja podczas blokowania następnego rzędu. Domyślnie jest wyłączone. Po przeczytaniu może być konieczne rozważenie włączenia tej opcji.

AKTUALIZACJA 2011-06-06 10:03

Innym powodem do zbadania tego sposobu myślenia jest fakt, że wszystkie transakcje przekraczają klucz podstawowy. Ponieważ PODSTAWOWY jest indeksem klastrowym w InnoDB, klucz PODSTAWOWY i sam wiersz są razem. Zatem przemierzanie rzędu i KLUCZ PODSTAWOWY są jednym i tym samym. Dlatego każda blokada indeksu na KLUCZU PODSTAWOWYM jest również blokadą na poziomie wiersza.

AKTUALIZACJA 2011-06-06 19:21

Sprawdź, jaką masz wartość auocommit . Jeśli funkcja automatycznego zatwierdzania jest wyłączona, widzę dwa (2) możliwe problemy

  1. aktualizowanie tego samego wiersza dwukrotnie w tej samej transakcji
  2. aktualizowanie tego samego wiersza w dwóch różnych transakcjach

W rzeczywistości STATUS POKAŻ INNODB SILNIKA wyświetlany w pytaniu ma dokładnie oba scenariusze.

RolandoMySQLDBA
źródło
Dzięki za wkład. Zauważyliśmy to również. Jestem zdezorientowany, dlaczego zmiany dwóch kolumn w tym samym rzędzie doprowadziłyby do impasu.
RedBlueThing
Dziękuję za twoje aktualizacje. Właśnie sprawdziłem nasze ustawienia i automatyczne zatwierdzanie jest włączone (tzn. Nie zmieniliśmy domyślnego).
RedBlueThing
@RedBlueThing Proszę przejrzeć poziom izolacji transakcji (zmienna to tx_isolation dev.mysql.com/doc/refman/5.5/en/… ). Jeśli nie ustawisz tej wartości, domyślną wartością będzie REPEATABLE-READ. możliwe, że inny poziom izolacji transakcji może pomóc w tej wyjątkowej sytuacji.
RolandoMySQLDBA
Dzięki. Sprawdzę to i skontaktuję się z tobą.
Jeszcze
Dziś rano odkryłem inny impas w naszych logach, który może rzucić nieco światła na ten problem. Zadałem to jako osobne pytanie, aby uprościć sprawę. dba.stackexchange.com/questions/3223/…
RedBlueThing
1

Odpowiedź Rolando z pewnością pomogła nam znaleźć drogę do właściwego rozwiązania. Jednak ostatecznie nie dostosowaliśmy naszej konfiguracji automatycznego zatwierdzania , naszych poziomów izolacji ani konfiguracji innodb_locks_unsafe_for_binlog .

Uważamy, że dziennik impasu opublikowany w pierwszym pytaniu jest wynikiem impasu, który później znaleźliśmy i opublikowaliśmy tutaj . Ponieważ rozwiązaliśmy problem z tymi dwoma zapytaniami, od tego czasu nie widzieliśmy żadnych impasów.

RedBlueThing
źródło
Chociaż nie mogłem znaleźć rozwiązania, cieszyłem się, że mogłem pomóc !!!
RolandoMySQLDBA
Dziękujemy za rozważenie moich sugestii i przypadkowych bełkotów MySQL (+1) !!!
RolandoMySQLDBA
@RolandoMySQLDBA Nie ma problemu;) Dzięki za pomoc.
RedBlueThing