MDEV-18590: galera.versioning_trx_id: Test failure: mysqltest: Result…

… content mismatch

Replicated events have time associated with them from originating
node which will be used for commit timestamp. Associated time can
be set in past before event is even applied.

For WSREP replication we don't need to use time information from
event.

Addressed review comments:
	  Jan Lindström <jan.lindstrom@galeracluster.com>

Signed-off-by: Julius Goryavsky <julius.goryavsky@mariadb.com>

mysql-test/suite/galera/disabled.def

@@ -13,7 +13,6 @@
 galera_as_slave_ctas : MDEV-28378 timeout
 galera_pc_recovery : MDEV-25199 cluster fails to start up
 galera_sequences : MDEV-32561 WSREP FSM failure: no such a transition REPLICATING -> COMMITTED
-versioning_trx_id : MDEV-18590 : galera.versioning_trx_id: Test failure: mysqltest: Result content mismatch
 galera_concurrent_ctas : MDEV-32779 galera_concurrent_ctas: assertion in the galera::ReplicatorSMM::finish_cert()
 galera_as_slave_replay : MDEV-32780 galera_as_slave_replay: assertion in the wsrep::transaction::before_rollback()
 galera_slave_replay : MDEV-32780 galera_as_slave_replay: assertion in the wsrep::transaction::before_rollback()

mysql-test/suite/galera/r/versioning_trx_id.result

@@ -17,7 +17,7 @@ a
 select count(*) from mysql.transaction_registry where begin_timestamp='0-0-0';
 count(*)
 0
-select count(*) from mysql.transaction_registry where begin_timestamp>=commit_timestamp;
+select count(*) from mysql.transaction_registry where begin_timestamp>commit_timestamp;
 count(*)
 0
 connection node_3;
@@ -34,7 +34,7 @@ a
 select count(*) from mysql.transaction_registry where begin_timestamp='0-0-0';
 count(*)
 0
-select count(*) from mysql.transaction_registry where begin_timestamp>=commit_timestamp;
+select count(*) from mysql.transaction_registry where begin_timestamp>commit_timestamp;
 count(*)
 0
 connection node_1;
@@ -50,7 +50,7 @@ a
 select count(*) from mysql.transaction_registry where begin_timestamp='0-0-0';
 count(*)
 0
-select count(*) from mysql.transaction_registry where begin_timestamp>=commit_timestamp;
+select count(*) from mysql.transaction_registry where begin_timestamp>commit_timestamp;
 count(*)
 0
 drop table t1;

mysql-test/suite/galera/t/versioning_trx_id.test

@@ -13,29 +13,29 @@ set session wsrep_sync_wait=15;
 insert into t1 (a) values (3),(4);
 select a from t1;
 select count(*) from mysql.transaction_registry where begin_timestamp='0-0-0';
-if (`SELECT count(*) from mysql.transaction_registry where begin_timestamp>=commit_timestamp`) {
+if (`SELECT count(*) from mysql.transaction_registry where begin_timestamp>commit_timestamp`) {
   select * from mysql.transaction_registry;
 }
-select count(*) from mysql.transaction_registry where begin_timestamp>=commit_timestamp;
+select count(*) from mysql.transaction_registry where begin_timestamp>commit_timestamp;
 
 --connection node_3
 set session wsrep_sync_wait=15;
 insert into t1 (a) values (5),(6);
 select a from t1;
 select count(*) from mysql.transaction_registry where begin_timestamp='0-0-0';
-if (`SELECT count(*) from mysql.transaction_registry where begin_timestamp>=commit_timestamp`) {
+if (`SELECT count(*) from mysql.transaction_registry where begin_timestamp>commit_timestamp`) {
   select * from mysql.transaction_registry;
 }
-select count(*) from mysql.transaction_registry where begin_timestamp>=commit_timestamp;
+select count(*) from mysql.transaction_registry where begin_timestamp>commit_timestamp;
 
 --connection node_1
 set session wsrep_sync_wait=15;
 select a from t1;
 select count(*) from mysql.transaction_registry where begin_timestamp='0-0-0';
-if (`SELECT count(*) from mysql.transaction_registry where begin_timestamp>=commit_timestamp`) {
+if (`SELECT count(*) from mysql.transaction_registry where begin_timestamp>commit_timestamp`) {
   select * from mysql.transaction_registry;
 }
-select count(*) from mysql.transaction_registry where begin_timestamp>=commit_timestamp;
+select count(*) from mysql.transaction_registry where begin_timestamp>commit_timestamp;
 
 drop table t1;
 

sql/log_event.cc

@@ -5554,7 +5554,10 @@ int Query_log_event::do_apply_event(rpl_group_info *rgi,
   */
   if (is_trans_keyword() || rpl_filter->db_ok(thd->db.str))
   {
-    thd->set_time(when, when_sec_part);
+#ifdef WITH_WSREP
+    if (!wsrep_thd_is_applying(thd))
+#endif
+      thd->set_time(when, when_sec_part);
     thd->set_query_and_id((char*)query_arg, q_len_arg,
                           thd->charset(), next_query_id());
     thd->variables.pseudo_thread_id= thread_id;		// for temp tables
@@ -7433,7 +7436,10 @@ int Load_log_event::do_apply_event(NET* net, rpl_group_info *rgi,
   */
   if (rpl_filter->db_ok(thd->db.str))
   {
-    thd->set_time(when, when_sec_part);
+#ifdef WITH_WSREP
+    if (!wsrep_thd_is_applying(thd))
+#endif
+      thd->set_time(when, when_sec_part);
     thd->set_query_id(next_query_id());
     thd->get_stmt_da()->opt_clear_warning_info(thd->query_id);
 
@@ -11629,7 +11635,10 @@ int Rows_log_event::do_apply_event(rpl_group_info *rgi)
       TIMESTAMP column to a table with one.
       So we call set_time(), like in SBR. Presently it changes nothing.
     */
-    thd->set_time(when, when_sec_part);
+#ifdef WITH_WSREP
+    if (!wsrep_thd_is_applying(thd))
+#endif
+      thd->set_time(when, when_sec_part);
 
      if (m_width == table->s->fields && bitmap_is_set_all(&m_cols))
       set_flags(COMPLETE_ROWS_F);

sql/log_event_old.cc

@@ -31,6 +31,9 @@
 #include "log_event_old.h"
 #include "rpl_record_old.h"
 #include "transaction.h"
+#ifdef WITH_WSREP
+#include "wsrep_mysqld.h"
+#endif /* WITH_WSREP */
 
 #if !defined(MYSQL_CLIENT) && defined(HAVE_REPLICATION)
 
@@ -203,7 +206,10 @@ Old_rows_log_event::do_apply_event(Old_rows_log_event *ev, rpl_group_info *rgi)
       TIMESTAMP column to a table with one.
       So we call set_time(), like in SBR. Presently it changes nothing.
     */
-    ev_thd->set_time(ev->when, ev->when_sec_part);
+#ifdef WITH_WSREP
+    if (!wsrep_thd_is_applying(thd))
+#endif
+      ev_thd->set_time(ev->when, ev->when_sec_part);
     /*
       There are a few flags that are replicated with each row event.
       Make sure to set/clear them before executing the main body of
@@ -1507,7 +1513,10 @@ int Old_rows_log_event::do_apply_event(rpl_group_info *rgi)
       TIMESTAMP column to a table with one.
       So we call set_time(), like in SBR. Presently it changes nothing.
     */
-    thd->set_time(when, when_sec_part);
+#ifdef WITH_WSREP
+    if (!wsrep_thd_is_applying(thd))
+#endif
+      thd->set_time(when, when_sec_part);
     /*
       There are a few flags that are replicated with each row event.
       Make sure to set/clear them before executing the main body of

sql/wsrep_applier.cc

@@ -182,16 +182,7 @@ int wsrep_apply_events(THD*        thd,
 
     /* Use the original server id for logging. */
     thd->set_server_id(ev->server_id);
-    thd->set_time();                            // time the query
-    thd->transaction.start_time.reset(thd);
     thd->lex->current_select= 0;
-    if (!ev->when)
-    {
-      my_hrtime_t hrtime= my_hrtime();
-      ev->when= hrtime_to_my_time(hrtime);
-      ev->when_sec_part= hrtime_sec_part(hrtime);
-    }
-
     thd->variables.option_bits=
       (thd->variables.option_bits & ~OPTION_SKIP_REPLICATION) |
       (ev->flags & LOG_EVENT_SKIP_REPLICATION_F ?  OPTION_SKIP_REPLICATION : 0);

sql/wsrep_high_priority_service.cc

@@ -197,6 +197,7 @@ int Wsrep_high_priority_service::start_transaction(
   const wsrep::ws_handle& ws_handle, const wsrep::ws_meta& ws_meta)
 {
   DBUG_ENTER(" Wsrep_high_priority_service::start_transaction");
+  m_thd->set_time();
   DBUG_RETURN(m_thd->wsrep_cs().start_transaction(ws_handle, ws_meta) ||
               trans_begin(m_thd));
 }
@@ -391,6 +392,7 @@ int Wsrep_high_priority_service::apply_toi(const wsrep::ws_meta& ws_meta,
                   };);
 #endif
 
+  thd->set_time();
   int ret= wsrep_apply_events(thd, m_rli, data.data(), data.size());
   if (ret != 0 || thd->wsrep_has_ignored_error)
   {