Início / dba / Perguntas / 3179
Accepted
RedBlueThing
Asked: 2011-06-06 22:54:51 +0800 CST

Problema ao decifrar um impasse em um log de status do innodb

  • 772

Estamos acessando o MySQL a partir do conector Microsoft ADO.NET.

Ocasionalmente, vemos o seguinte impasse em nosso status innodb e não conseguimos identificar a causa do problema. Parece que a transação (2) está esperando e segurando o mesmo bloqueio?

------------------------
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)

Lemos este artigo sobre o próximo bloqueio de chave, mas não parece se aplicar a nós porque não estamos fazendo seleções para atualização.

Atualizar

Esta manhã, descobri uma assinatura de impasse ligeiramente diferente, que pode ser a causa raiz desse impasse. Publiquei esse impasse como uma pergunta separada para manter as coisas simples. Atualizarei aqui se puder confirmar que a outra pergunta é a causa.

mysql innodb

2 respostas

  1. Aqui está o que estou vendo

    Vejo três consultas, todas quase idênticas.

    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;

    As diferenças

    TRANSAÇÃO 1

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

    TRANSAÇÃO 2

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

    Observe que os valores da coluna estão invertidos. Normalmente, um deadlock ocorre quando duas transações diferentes estão acessando dois bloqueios de duas tabelas com TX1 (Transação 1) obtendo a linha A e depois a linha B enquanto TX2 está obtendo a linha B e depois a linha A. Nesse caso, é TX1 e TX2 são acessando a mesma linha, mas alterando duas colunas diferentes (iphone_device_time,last_checkin).

    Os valores não fazem sentido. Às 5:24:42, seu último check-in foi às 5:35:07. Dez minutos e 27 segundos depois (5:35:07 - 05:24:42), os valores da coluna são invertidos.

    A grande questão é: Por que o TX1 fica parado por quase 11 min???

    Isso não é realmente uma resposta. Esta é apenas a largura de banda e toda de mim. Espero que essas observações ajudem.

    ATUALIZAÇÃO 2011-06-06 09:57

    Por favor, verifique este link sobre innodb_locks_unsafe_for_binlog : A razão pela qual sugiro ler isso é outra coisa que vi em sua exibição INNODB STATUS. A frase lock_mode X (bloqueio exclusivo) e lock_mode S (bloqueio compartilhado) indica que ambos os bloqueios estão sendo impostos (ou tentando impor) na mesma linha. Pode haver alguma serialização interna acontecendo fazendo o bloqueio da próxima linha. O padrão é DESLIGADO. Depois de ler isso, você pode precisar considerar ativá-lo.

    ATUALIZAÇÃO 2011-06-06 10:03

    Outro motivo para examinar essa linha de pensamento é o fato de que todas as transações estão passando pela chave PRIMÁRIA. Como o PRIMARY é um índice clusterizado no InnoDB, a chave PRIMARY e a própria linha estão juntas. Assim, percorrer uma linha e a PRIMARY KEY são a mesma coisa. Portanto, qualquer bloqueio de índice na PRIMARY KEY também é um bloqueio de nível de linha.

    ATUALIZAÇÃO 2011-06-06 19:21

    Verifique qual valor de auocommit você tem . Se a confirmação automática estiver desativada, posso ver dois (2) problemas possíveis

    1. atualizando a mesma linha duas vezes na mesma transação
    2. atualizando a mesma linha em duas transações diferentes

    Na verdade, o SHOW ENGINE INNODB STATUS que você mostra na pergunta tem exatamente os dois cenários.

    • 6
  2. Best Answer

    A resposta de Rolando foi certamente útil para nos colocar no caminho para a solução certa. No entanto, não ajustamos nossa configuração de autocommit , nossos níveis de isolamento ou a configuração innodb_locks_unsafe_for_binlog .

    Acreditamos que o registro de impasse que postamos nesta primeira pergunta é resultado do impasse que posteriormente encontramos e publicamos aqui . Como resolvemos o problema com essas duas consultas, não vimos nenhum impasse desde então.

    • 1

relate perguntas