Dados confirmados do MySQL não vistos para selecionar a consulta

Contexto: A estrutura usada é Spring e todas as consultas são executadas com JdbcTemplate. A versão do Mysql Server é 5.6.19. O padrão tableé um InnoDB tablee o padrão auto commitde leitura repetível e nível de isolamento está definido.

Problema : Insertacontece dentro de uma transação e uma selectque lê os mesmos dados inseridos não os vê. As selectcorridas após o inserte depois da inserttransação tem commited.

Eu habilitei o log de bin e o log geral no mysql. Registros relevantes abaixo

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/*!*/;

Log de consulta

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, First insert(249935389) não deve fazer parte da transação. É uma chamada de API separada e completamente independente. Pode ser primavera misturando-o com a transação ou estou lendo o log errado? AFAIK, pois está no mesmo encadeamento, implica que a inserção está na transação.

Os próximos dois insertsfazem parte da transação e parece que eles confirmam. (249936514). Agora a consulta de seleção (a última no log geral) é executada após a confirmação e não vê os dados. Retorna 0 linhas. Como isso pode acontecer considerando os dados committed? Ou é o que commitnão está no fio 40? Uma vez que não possui o ID do segmento.

Para resumir, tenho duas perguntas.

1. O que está BEGINno binlog antes da INSERT INTO user_geo_loc(que não faz parte da transação), é um erro do spring / Jdbc ou MySql simplesmente faz isso porque sabe que essa transação já foi confirmada (como as transações são gravadas no binlog quando conseguiu) e, portanto, nunca seria revertida.

2. Dado que a confirmação ocorre antes da seleção (a confirmação é às 14:16:06 e a seleção às 14:16:07), como é que a seleção não retorna a linha inserida pela transação?

Isso é extremamente desconcertante. Qualquer ajuda seria apreciada

Nota: As consultas no compartimento e no log de consultas foram editadas para remover informações confidenciais. Mas a essência das consultas permanece a mesma

Editar: atualizado com o log geral e o log de consulta com um exemplo detalhado.

Eu tento fazer uma hipótese sobre a segunda pergunta:

Dado que a confirmação ocorre antes da seleção (a confirmação é às 14:16:06 e a seleção às 14:16:07), como é que a seleção não retorna a linha inserida pela transação?

As transações são gerenciadas pelo Spring. Portanto, seria possível que antes de executar a selectmola tenha levantado uma start transactionou já tenha usado a conexão para executar outra consulta.

Inicio uma primeira sessão em que simulo uma inserção em uma tabela 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)

Crio uma nova sessão, session2, em que autocommitestá definido como 0. Nesta nova sessão, uma transação é iniciada implicitamente ao executar uma seleção.

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)

Vá para session1 para confirmar a inserção.

session1> commit;

Agora vá novamente para a sessão2:

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

Session2 não pode ver a linha inserida. Se a commitfor gerado na sessão2, podemos ver uma nova linha inserida na sessão1

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

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

O log geral se parece com:

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

A primeira linha está relacionada à sessão 2. É quando a sessão 2 abre a transação.

Não sei se é isso que acontece no seu caso. Você pode verificar em seu log geral se o connection_id 36 foi usado para outras consultas. Deixe-nos saber.