Jan Lindström (Inactive) added a comment - 2015-02-17 09:51 Lets try to repeat first using same sane defaults. From InnoDB point of view transaction should be executed exactly similar way as in master if the set of actual statements are exactly the same. If in RBR some statement is replicated differently then we have different case. Here is what we understant to this point of time. We have two machines A and B, both contain the same table but table contents differ. Thus in machine A master executes selects (to find out the rows that differ and how), inserts, replaces, deletes to modify table rows to match table in B. This creates a big transaction that takes ~7h on master, on transaction commit master writes ~1G binlog that is then transfered to slave for execution. For some reason this execution takes 10x time compared with master. I did debug the slave, and there was basically only one SQL-thread doing something, executing this one big transaction, statement by statement.

Elena Stepanova added a comment - 2015-03-04 03:07 Tentative test case (should be run with the increased testcase-timeout and maybe suite-timeout; although there is no need to wait till the end of the test, as soon as the problem is obvious it can be interrupted). --source include/master-slave.inc --source include/have_binlog_format_row.inc --source include/have_xtradb.inc   let $num = 10000000; let $n = $num;   CREATE TABLE t (pk int auto_increment primary key ) engine=InnoDB; --sync_slave_with_master   --connection master BEGIN ; --disable_query_log --echo # Inserting $n rows... while ($n) { eval INSERT INTO t VALUES ($num + 1 - $n); dec $n; } --echo # Inserted $n rows --enable_query_log COMMIT ;   --connection slave while (` SELECT COUNT (*) < $num FROM t`) { --exec $MYSQL -h 127.0.0.1 -P $SLAVE_MYPORT -uroot -e "SHOW ENGINE INNODB STATUS \G" | grep -E 'ACTIVE|Number of rows inserted' --sleep 5 } --echo # Final one: --exec $MYSQL -h 127.0.0.1 -P $SLAVE_MYPORT -uroot -e "SHOW ENGINE INNODB STATUS \G" | grep 'Number of rows inserted'   --connection master DROP TABLE t;   --source include/rpl_end.inc If the problem is reproducible, the 'Number of rows inserted' will grow slower and slower while the slave progresses through the huge transaction. I am running the test now, it will take a while. With 1M rows it's not convincing, that's why we couldn't reproduce it in the initial attempts.

Jan Lindström (Inactive) added a comment - 2015-03-04 13:56 Problem is on /********************************************************************//** This special handling is really to overcome the limitations of MySQL's binlogging. We need to eliminate the non-determinism that will arise in INSERT ... SELECT type of statements, since MySQL binlog only stores the min value of the autoinc interval. Once that is fixed we can get rid of the special lock handling. @return DB_SUCCESS if all OK else error code */ UNIV_INTERN dberr_t ha_innobase::innobase_lock_autoinc(void) /*====================================*/ { dberr_t error = DB_SUCCESS;   ut_ad(!srv_read_only_mode);   switch (innobase_autoinc_lock_mode) { case AUTOINC_NO_LOCKING: /* Acquire only the AUTOINC mutex. */ dict_table_autoinc_lock(prebuilt->table); break;   case AUTOINC_NEW_STYLE_LOCKING: /* For simple (single/multi) row INSERTs, we fallback to the old style only if another transaction has already acquired the AUTOINC lock on behalf of a LOAD FILE or INSERT ... SELECT etc. type of statement. */ /* NOTE: on master above example we have thd_sql_command(user_thd) == SQLCOM_INSERT on slave we have thd_sql_command(user_thd) == SQLCOM_END */ if (thd_sql_command(user_thd) == SQLCOM_INSERT || thd_sql_command(user_thd) == SQLCOM_REPLACE) { dict_table_t* ib_table = prebuilt->table;   /* Acquire the AUTOINC mutex. */ dict_table_autoinc_lock(ib_table);   /* We need to check that another transaction isn't already holding the AUTOINC lock on the table. */ if (ib_table->n_waiting_or_granted_auto_inc_locks) { /* Release the mutex to avoid deadlocks. */ dict_table_autoinc_unlock(ib_table); } else { break; /* On above case, master executes this not old style locking, slave naturally takes old style lock for every INSERT */ } } /* Fall through to old style locking. */   case AUTOINC_OLD_STYLE_LOCKING: error = row_lock_table_autoinc_for_mysql(prebuilt);   if (error == DB_SUCCESS) {   /* Acquire the AUTOINC mutex. */ dict_table_autoinc_lock(prebuilt->table); } break;   default: ut_error; }   return(error); }

Jan Lindström (Inactive) added a comment - 2015-03-05 12:14 Fixed on 5.5: commit f66fbe8ce0ff4ffcd6a6c185f9b3d25bd9f67f8d Author: Jan Lindström <jan.lindstrom@mariadb.com> Date: Thu Mar 5 12:05:59 2015 +0200 MDEV-7578 :Slave is ~10x slower to execute set of statements compared to master when using RBR Analysis: On master when executing (single/multi) row INSERTs/REPLACEs InnoDB fallback to old style autoinc locks (table locks) only if another transaction has already acquired the AUTOINC lock. Instead on slave as we are executing log_events and sql_command is not correctly set, InnoDB does not use new style autoinc locks when it could. Fix: Use new style autoinc locks also when thd_sql_command(user_thd) == SQLCOM_END i.e. this is RBR event.