Datos confirmados de MySQL no vistos para seleccionar consulta

13

Contexto: el marco utilizado es Spring y todas las consultas se ejecutan con JdbcTemplate. La versión del servidor Mysql es 5.6.19. El valor tablees un valor InnoDB tablepredeterminado auto commity se establece una lectura repetible de nivel de aislamiento.

Problema : Insertsucede dentro de una transacción y el selectque lee los mismos datos insertados no ve los datos. Las selectcarreras después de la inserty después de la inserttransacción tiene commited.

He habilitado bin log así como también log general en mysql. Registros relevantes a continuación

bin-log:

SET TIMESTAMP=1438265764/*!*/;
BEGIN
/*!*/;
# at 249935389
#150730 14:16:04 server id 1  end_log_pos 249935606 CRC32 0xa6aca292    Query   thread_id=40    exec_time=0     error_code=0
SET TIMESTAMP=1438265764/*!*/;
insert into user_geo_loc_latest(user_id, lat, lng) values(x,y,z) on duplicate key update lat=y, lng=z
/*!*/;
# at 249935606
#150730 14:16:06 server id 1  end_log_pos 249936255 CRC32 0x2a52c734    Query   thread_id=40    exec_time=0     error_code=0
SET TIMESTAMP=1438265766/*!*/;
INSERT INTO table(txnid) VALUES ('885851438265675046')
/*!*/;
# at 249936255
#150730 14:16:06 server id 1  end_log_pos 249936514 CRC32 0x6cd85eb5    Query   thread_id=40    exec_time=0     error_code=0
SET TIMESTAMP=1438265766/*!*/;
INSERT INTO table2(x) VALUES (y)
/*!*/;
# at 249936514
#150730 14:16:06 server id 1  end_log_pos 249936545 CRC32 0xceb9ec56    Xid = 9406873
COMMIT/*!*/;

Registro de consultas

150730 14:16:04    40 Query ...
....
40 Query     select count(*) from table where txnid = '885851438265675046'
                   40 Query     select @@session.tx_read_only
                   40 Query     INSERT INTO table(txnid) VALUES ('885851438265675046')
                   40 Query     select @@session.tx_read_only
                   40 Query     INSERT INTO table2(x) values(y)
                   40 Query     commit
....
150730 14:16:07    36 Query     select pp.*, b.create_date from table pp left join bill b on pp.bill_id = b.bill_id where pp.txnid = '885851438265675046'

Curiosamente, Primero insert(249935389) no debería ser parte de la transacción en absoluto. Es una llamada API separada y completamente no relacionada. ¿Podría ser primavera mezclarlo con la transacción o estoy leyendo mal el registro? AFAIK ya que está en el mismo hilo, implica que el inserto está en la transacción.

Los siguientes dos insertsson parte de la transacción y parece que se compromete. (249936514). Ahora la consulta de selección (la última en el registro general) se ejecuta después de la confirmación y no ve los datos. Devuelve 0 filas. ¿Cómo puede suceder esto teniendo en cuenta los datos committed? ¿O commitno está en el hilo 40? Ya que no tiene el id del hilo.

Para resumir, tengo dos preguntas.

  1. ¿ BEGINEstá en el binlog estar antes del INSERT INTO user_geo_loc(que no es parte de la transacción), es un error con spring / Jdbc o MySql simplemente hace esto ya que sabe que esta transacción ya se ha comprometido (ya que las transacciones se escriben en binlog cuando han tuvo éxito) y, por lo tanto, nunca se revierte

  2. Dado que la confirmación ocurre antes de la selección (la confirmación es a las 14:16:06 y la selección es a las 14:16:07) ¿cómo es que la selección no devuelve la fila insertada por la transacción?

Esto es extremadamente desconcertante. Cualquier ayuda sería apreciada

Nota: Las consultas tanto en el bin como en el registro de consultas se han editado para eliminar información confidencial. Pero la esencia de las consultas sigue siendo la misma.

Editar: actualizado con registro general y registro de consultas con un ejemplo detallado.

Ahmed Aeon Axan
fuente
Lo etiquetó 5.5, pero mencionó 5.6; cual es ¿Está involucrada la replicación?
Rick James
@ RickJames lo siento, es 5.6.19. He actualizado la pregunta con el ejemplo de consulta y registro de bin. Además, no hay replicación involucrada. Encendí bin log solo después de notar el problema para depurarlo. Gracias
Ahmed Aeon Axan
Gracias, eso ayuda. No veo una BEGINo START TRANSACTION. ¿Estás, en cambio, usando autocommit=0? (Prefiero comenzar ... comprometer; aclara el alcance de la transacción.)
Rick James
Por lo tanto, el marco (spring) gestiona las transacciones y generalmente establece autocommit = 0 y se compromete al final. Supongo que no vemos autocommit = 0 aquí porque la conexión ya estaba en ese estado.
Ahmed Aeon Axan

Respuestas:

3

Intento hacer una hipótesis sobre la segunda pregunta:

Dado que la confirmación ocurre antes de la selección (la confirmación es a las 14:16:06 y la selección es a las 14:16:07) ¿cómo es que la selección no devuelve la fila insertada por la transacción?

Spring gestiona las transacciones. Por lo tanto, es posible que antes de ejecutar el selectresorte haya generado una start transactiono ya haya utilizado la conexión para ejecutar otra consulta.

Comienzo una primera sesión donde simulo una inserción en una tabla t:

session1> create table t (i int auto_increment primary key);
Query OK, 0 rows affected (0,32 sec)

session1> insert into t values();
Query OK, 1 row affected (0,00 sec)

session1> select * from t;
+---+
| i |
+---+
| 1 |
+---+
1 row in set (0,00 sec)

session1> start transaction;
Query OK, 0 rows affected (0,00 sec)

session1> insert into t values();
Query OK, 1 row affected (0,00 sec)

Creo una nueva sesión, session2, donde autocommitse establece en 0. En esta nueva sesión, una transacción se inicia implícitamente cuando se ejecuta una selección.

session2> set autocommit = 0;
Query OK, 0 rows affected (0,00 sec)

session2> select * from t;  -- this starts a transaction
+---+
| i |
+---+
| 1 |
+---+
1 rows in set (0,00 sec)

Mover a sesión1 para confirmar la inserción.

session1> commit;

Ahora muévase nuevamente a la sesión2:

session2> select * from t;
+---+
| i |
+---+
| 1 |
+---+
1 row in set (0,00 sec)

Session2 no puede ver la fila recién insertada. Si commitse genera un a en la sesión 2, podemos ver una nueva fila insertada en la sesión 1

session2> commit
1 row in set (0,00 sec)

session2> select * from t;
+---+
| i |
+---+
| 1 |
| 2 |
+---+
2 rows in set (0,00 sec)

El registro general se ve así:

150804 14:04:10     2 Query select * from t

150804 14:04:30     1 Query start transaction
150804 14:04:39     1 Query insert into t values ()
150804 14:04:44     1 Query commit
150804 14:04:51     2 Query select * from t

150804 14:05:07     2 Query commit
150804 14:05:10     2 Query select * from t

La primera fila está relacionada con la sesión 2. Es cuando la sesión 2 abre la transacción.

No sé si esto es lo que sucede en tu caso. Puede verificar en su registro general si se utilizó connection_id 36 para otras consultas. Déjanos saber

Giovanni
fuente