Problemas para descifrar un punto muerto en un registro de estado innodb

16

Estamos accediendo a MySQL desde el conector ADO.NET de Microsoft.

Ocasionalmente, vemos el siguiente punto muerto en nuestro estado innodb y no hemos podido identificar la causa del problema. ¿Parece que la transacción (2) está esperando y manteniendo el mismo bloqueo?

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

Leemos este artículo sobre el próximo bloqueo de teclas, pero no parece aplicarse a nosotros porque no estamos haciendo selecciones para la actualización.

Actualizar

Esta mañana descubrí una firma de punto muerto ligeramente diferente que podría ser la causa principal de este punto muerto. He publicado ese punto muerto como una pregunta separada para mantener las cosas simples. Actualizaré aquí si puedo confirmar que la otra pregunta es la causa.

mysql innodb deadlock ado.net RedBlueThing
fuente
He actualizado mi respuesta con más ancho de banda y rendimiento.
RolandoMySQLDBA
Actualicé
Por cierto, obtienes un +1 para esta pregunta porque este tipo de pregunta debería mantener a los DBA alerta.
RolandoMySQLDBA

Respuestas:

6

Esto es lo que estoy viendo.

Veo tres consultas, todas casi 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;

Las diferencias

TRANSACCION 1

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

TRANSACCION 2

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

Tenga en cuenta que los valores de la columna están invertidos. Normalmente, se produce un punto muerto cuando dos transacciones diferentes acceden a dos bloqueos de dos tablas con TX1 (Transacción 1) obteniendo la fila A y luego la fila B mientras TX2 obtiene la fila B y luego la fila A. En este caso, son TX1 y TX2 son accediendo a la misma fila pero cambiando dos columnas diferentes (iphone_device_time, last_checkin).

Los valores no tienen ningún sentido. A las 5:24:42, tu último registro fue a las 5:35:07. Diez minutos y 27 segundos después (5:35:07 - 05:24:42), los valores de la columna se invierten.

La gran pregunta es: ¿por qué se retrasa TX1 durante casi 11 minutos?

Esto no es realmente una respuesta. Esto es solo ancho de banda y todo de mí. Espero que estas observaciones ayuden.

ACTUALIZACIÓN 2011-06-06 09:57

Consulte este enlace sobre innodb_locks_unsafe_for_binlog : la razón por la que sugiero leer esto es algo más que vi en su pantalla INNODB STATUS. La frase lock_mode X (bloqueo exclusivo) y lock_mode S (bloqueo compartido) indica que ambos bloqueos se imponen (o intentan imponer) en la misma fila. Puede haber alguna serialización interna en el bloqueo de la siguiente fila. El valor predeterminado es OFF. Después de leer esto, es posible que deba considerar habilitarlo.

ACTUALIZACIÓN 2011-06-06 10:03

Otra razón para examinar esta línea de pensamiento es el hecho de que todas las transacciones atraviesan la clave PRIMARIA. Dado que PRIMARY es un índice agrupado en InnoDB, la clave PRIMARY y la fila en sí están juntas. Por lo tanto, atravesar una fila y la CLAVE PRIMARIA son lo mismo. Por lo tanto, cualquier bloqueo de índice en PRIMARY KEY también es un bloqueo de nivel de fila.

ACTUALIZACIÓN 2011-06-06 19:21

Verifique qué valor de compromiso tiene . Si la confirmación automática está desactivada, puedo ver dos (2) posibles problemas

  1. actualizar la misma fila dos veces en la misma transacción
  2. actualizar la misma fila en dos transacciones diferentes

De hecho, el ESTADO SHOW ENGINE INNODB que muestra en la pregunta tiene exactamente ambos escenarios.

RolandoMySQLDBA
fuente
Gracias por tu contribución. Lo notamos también. Estoy confundido por qué los cambios en dos columnas en la misma fila resultarían en un punto muerto.
RedBlueThing
Gracias por tus actualizaciones. Acabo de comprobar nuestra configuración y la confirmación automática está activada (es decir, no hemos cambiado la configuración predeterminada).
RedBlueThing
@RedBlueThing Por favor, mirar por encima de su nivel de aislamiento (variable es tx_isolation dev.mysql.com/doc/refman/5.5/en/... ). Si no configura esto, el valor predeterminado es REPEATABLE-READ. Es posible que un nivel de aislamiento de transacción diferente pueda ayudar con esta situación única.
RolandoMySQLDBA
Gracias. Lo comprobaré y te responderé. Gracias de nuevo por su persistencia :)
RedBlueThing
Descubrí un punto muerto diferente en nuestros registros esta mañana que podría arrojar algo de luz sobre este problema. Lo publiqué como una pregunta separada para mantener las cosas simples. dba.stackexchange.com/questions/3223/…
RedBlueThing
1

La respuesta de Rolando fue ciertamente útil para ayudarnos a encontrar la solución correcta. Sin embargo, finalmente no ajustamos nuestra configuración de confirmación automática , nuestros niveles de aislamiento o la configuración innodb_locks_unsafe_for_binlog .

Creemos que el registro de punto muerto que publicamos en esta primera pregunta es el resultado del punto muerto que posteriormente encontramos y publicamos aquí . Desde que resolvimos el problema con esas dos consultas, no hemos visto ningún punto muerto desde entonces.

RedBlueThing
fuente
Aunque no pude encontrar la solución, ¡me alegré de poder ayudar!
RolandoMySQLDBA
¡Gracias por considerar mis sugerencias y balbuceos aleatorios de MySQL (+1)!
RolandoMySQLDBA
@RolandoMySQLDBA No hay problema;) Gracias por la ayuda.
RedBlueThing 01 de