misc replication bugfixes including some needed modifications in IO_CACHE

likely() and unlikely() branch prediction compiler hint macros
clean-up of comments


include/my_global.h:
  added likely() and unlikely() macros to help some compilers optimize
  the code for architecture-specific branch prediction policies
include/my_sys.h:
  coverted my_b_append_tell() from macro to a function as it needed to be more
  complex to avoid a potential race condition
mysql-test/mysql-test-run.sh:
  hostname-independent relay log name to have consistent SHOW SLAVE STATUS
  output
mysql-test/r/rpl000014.result:
  result update
mysql-test/r/rpl000015.result:
  result update
mysql-test/r/rpl000016.result:
  result update
mysql-test/r/rpl_log.result:
  result update
mysql-test/t/rpl000017-slave.sh:
  proper cleanup of old logs
mysys/mf_iocache.c:
  cosmetic changes + more debugging asserts
mysys/mf_iocache2.c:
  my_b_append_tell()
  cleanup of comments
sql/log.cc:
  fix potential bug - do not rotate log in the middle of event
sql/slave.cc:
  do not write stop events when the server does not actually stop but just 
  rotates the log
  fixed race between queue_event() and show_slave_status()
  clean-up of comments
sql/slave.h:
  added ignore_stop_event flag to SLAVE_LOG_INFO

include/my_global.h

@@ -51,6 +51,22 @@
 #endif
 #endif /* _WIN32... */
 
+/* The macros below are borrowed from include/linux/compiler.h in the
+   Linux kernel. Use them to indicate the likelyhood of the truthfulness
+   of a condition. This serves two purposes - newer versions of gcc will be
+   able to optimize for branch predication, which could yield siginficant
+   performance gains in frequently executed sections of the code, and the
+   other reason to use them is for documentation
+*/
+
+#if __GNUC__ == 2 && __GNUC_MINOR__ < 96
+#define __builtin_expect(x, expected_value) (x)
+#endif
+
+#define likely(x)	__builtin_expect((x),1)
+#define unlikely(x)	__builtin_expect((x),0)
+
+
 /* Fix problem with S_ISLNK() on Linux */
 #if defined(HAVE_LINUXTHREADS)
 #undef  _GNU_SOURCE

include/my_sys.h

@@ -436,8 +436,9 @@ typedef int (*qsort2_cmp)(const void *, const void *, const void *);
 
 #define my_b_tell(info) ((info)->pos_in_file + \
 			 (uint) (*(info)->current_pos - (info)->request_pos))
-#define my_b_append_tell(info) ((info)->end_of_file + \
-			 (uint) ((info)->write_pos - (info)->write_buffer))
+
+/* tell write offset in the SEQ_APPEND cache */
+my_off_t my_b_append_tell(IO_CACHE* info);
 
 #define my_b_bytes_in_cache(info) (uint) (*(info)->current_end - \
 					  *(info)->current_pos)

mysql-test/mysql-test-run.sh

@@ -832,6 +832,7 @@ start_slave()
   slave_args="--no-defaults $master_info \
   	    --exit-info=256 \
           --log-bin=$MYSQL_TEST_DIR/var/log/$slave_ident-bin \
+          --relay-log=$MYSQL_TEST_DIR/var/log/$slave_ident-relay-bin \
           --log-slave-updates \
           --log=$slave_log \
           --basedir=$MY_BASEDIR \

mysql-test/r/rpl000014.result

@@ -8,21 +8,21 @@ File	Position	Binlog_do_db	Binlog_ignore_db
 master-bin.001	79		
 show slave status;
 Master_Host	Master_User	Master_Port	Connect_retry	Master_Log_File	Read_Master_Log_Pos	Relay_Log_File	Relay_Log_Pos	Relay_Master_Log_File	Slave_IO_Running	Slave_SQL_Running	Replicate_do_db	Replicate_ignore_db	Last_errno	Last_error	Skip_counter	Exec_master_log_pos
-127.0.0.1	root	MASTER_PORT	1	master-bin.001	79	mysql-relay-bin.002	120	master-bin.001	Yes	Yes			0		0	79
+127.0.0.1	root	MASTER_PORT	1	master-bin.001	79	slave-relay-bin.002	120	master-bin.001	Yes	Yes			0		0	79
 change master to master_log_pos=73;
 slave stop;
 change master to master_log_pos=73;
 show slave status;
 Master_Host	Master_User	Master_Port	Connect_retry	Master_Log_File	Read_Master_Log_Pos	Relay_Log_File	Relay_Log_Pos	Relay_Master_Log_File	Slave_IO_Running	Slave_SQL_Running	Replicate_do_db	Replicate_ignore_db	Last_errno	Last_error	Skip_counter	Exec_master_log_pos
-127.0.0.1	root	MASTER_PORT	1	master-bin.001	73	mysql-relay-bin.001	4	master-bin.001	No	No			0		0	73
+127.0.0.1	root	MASTER_PORT	1	master-bin.001	73	slave-relay-bin.001	4	master-bin.001	No	No			0		0	73
 slave start;
 show slave status;
 Master_Host	Master_User	Master_Port	Connect_retry	Master_Log_File	Read_Master_Log_Pos	Relay_Log_File	Relay_Log_Pos	Relay_Master_Log_File	Slave_IO_Running	Slave_SQL_Running	Replicate_do_db	Replicate_ignore_db	Last_errno	Last_error	Skip_counter	Exec_master_log_pos
-127.0.0.1	root	MASTER_PORT	1	master-bin.001	73	mysql-relay-bin.001	4	master-bin.001	Yes	Yes			0		0	73
+127.0.0.1	root	MASTER_PORT	1	master-bin.001	73	slave-relay-bin.001	4	master-bin.001	Yes	Yes			0		0	73
 change master to master_log_pos=173;
 show slave status;
 Master_Host	Master_User	Master_Port	Connect_retry	Master_Log_File	Read_Master_Log_Pos	Relay_Log_File	Relay_Log_Pos	Relay_Master_Log_File	Slave_IO_Running	Slave_SQL_Running	Replicate_do_db	Replicate_ignore_db	Last_errno	Last_error	Skip_counter	Exec_master_log_pos
-127.0.0.1	root	MASTER_PORT	1	master-bin.001	173	mysql-relay-bin.001	4	master-bin.001	Yes	Yes			0		0	173
+127.0.0.1	root	MASTER_PORT	1	master-bin.001	173	slave-relay-bin.001	4	master-bin.001	Yes	Yes			0		0	173
 show master status;
 File	Position	Binlog_do_db	Binlog_ignore_db
 master-bin.001	79		

mysql-test/r/rpl000015.result

@@ -9,16 +9,16 @@ Master_Host	Master_User	Master_Port	Connect_retry	Master_Log_File	Read_Master_Lo
 change master to master_host='127.0.0.1';
 show slave status;
 Master_Host	Master_User	Master_Port	Connect_retry	Master_Log_File	Read_Master_Log_Pos	Relay_Log_File	Relay_Log_Pos	Relay_Master_Log_File	Slave_IO_Running	Slave_SQL_Running	Replicate_do_db	Replicate_ignore_db	Last_errno	Last_error	Skip_counter	Exec_master_log_pos
-127.0.0.1	test	MASTER_PORT	60		4	mysql-relay-bin.001	4		No	No			0		0	0
+127.0.0.1	test	MASTER_PORT	60		4	slave-relay-bin.001	4		No	No			0		0	0
 change master to master_host='127.0.0.1',master_user='root',
 master_password='',master_port=MASTER_PORT;
 show slave status;
 Master_Host	Master_User	Master_Port	Connect_retry	Master_Log_File	Read_Master_Log_Pos	Relay_Log_File	Relay_Log_Pos	Relay_Master_Log_File	Slave_IO_Running	Slave_SQL_Running	Replicate_do_db	Replicate_ignore_db	Last_errno	Last_error	Skip_counter	Exec_master_log_pos
-127.0.0.1	root	MASTER_PORT	60		4	mysql-relay-bin.001	4		No	No			0		0	0
+127.0.0.1	root	MASTER_PORT	60		4	slave-relay-bin.001	4		No	No			0		0	0
 slave start;
 show slave status;
 Master_Host	Master_User	Master_Port	Connect_retry	Master_Log_File	Read_Master_Log_Pos	Relay_Log_File	Relay_Log_Pos	Relay_Master_Log_File	Slave_IO_Running	Slave_SQL_Running	Replicate_do_db	Replicate_ignore_db	Last_errno	Last_error	Skip_counter	Exec_master_log_pos
-127.0.0.1	root	MASTER_PORT	60	master-bin.001	79	mysql-relay-bin.001	120	master-bin.001	Yes	Yes			0		0	79
+127.0.0.1	root	MASTER_PORT	60	master-bin.001	79	slave-relay-bin.001	120	master-bin.001	Yes	Yes			0		0	79
 drop table if exists t1;
 create table t1 (n int);
 insert into t1 values (10),(45),(90);

mysql-test/r/rpl000016.result

@@ -15,7 +15,7 @@ create table t1 (s text);
 insert into t1 values('Could not break slave'),('Tried hard');
 show slave status;
 Master_Host	Master_User	Master_Port	Connect_retry	Master_Log_File	Read_Master_Log_Pos	Relay_Log_File	Relay_Log_Pos	Relay_Master_Log_File	Slave_IO_Running	Slave_SQL_Running	Replicate_do_db	Replicate_ignore_db	Last_errno	Last_error	Skip_counter	Exec_master_log_pos
-127.0.0.1	root	MASTER_PORT	60	master-bin.001	234	mysql-relay-bin.001	275	master-bin.001	Yes	Yes			0		0	234
+127.0.0.1	root	MASTER_PORT	60	master-bin.001	234	slave-relay-bin.001	275	master-bin.001	Yes	Yes			0		0	234
 select * from t1;
 s
 Could not break slave
@@ -42,7 +42,7 @@ master-bin.003
 insert into t2 values (65);
 show slave status;
 Master_Host	Master_User	Master_Port	Connect_retry	Master_Log_File	Read_Master_Log_Pos	Relay_Log_File	Relay_Log_Pos	Relay_Master_Log_File	Slave_IO_Running	Slave_SQL_Running	Replicate_do_db	Replicate_ignore_db	Last_errno	Last_error	Skip_counter	Exec_master_log_pos
-127.0.0.1	root	MASTER_PORT	60	master-bin.003	155	mysql-relay-bin.001	793	master-bin.003	Yes	Yes			0		0	155
+127.0.0.1	root	MASTER_PORT	60	master-bin.003	155	slave-relay-bin.001	755	master-bin.003	Yes	Yes			0		0	155
 select * from t2;
 m
 34
@@ -65,7 +65,7 @@ slave stop;
 slave start;
 show slave status;
 Master_Host	Master_User	Master_Port	Connect_retry	Master_Log_File	Read_Master_Log_Pos	Relay_Log_File	Relay_Log_Pos	Relay_Master_Log_File	Slave_IO_Running	Slave_SQL_Running	Replicate_do_db	Replicate_ignore_db	Last_errno	Last_error	Skip_counter	Exec_master_log_pos
-127.0.0.1	root	MASTER_PORT	60	master-bin.006	445	mysql-relay-bin.004	1376	master-bin.006	Yes	Yes			0		0	445
+127.0.0.1	root	MASTER_PORT	60	master-bin.006	445	slave-relay-bin.004	1229	master-bin.006	Yes	Yes			0		0	445
 lock tables t3 read;
 select count(*) from t3 where n >= 4;
 count(*)

mysql-test/r/rpl_log.result

@@ -75,7 +75,7 @@ slave-bin.002	115	Query	1	62	use test; insert into t1 values (1)
 slave-bin.002	175	Query	1	122	use test; drop table t1
 show slave status;
 Master_Host	Master_User	Master_Port	Connect_retry	Master_Log_File	Read_Master_Log_Pos	Relay_Log_File	Relay_Log_Pos	Relay_Master_Log_File	Slave_IO_Running	Slave_SQL_Running	Replicate_do_db	Replicate_ignore_db	Last_errno	Last_error	Skip_counter	Exec_master_log_pos
-127.0.0.1	root	MASTER_PORT	1	master-bin.002	170	mysql-relay-bin.002	935	master-bin.002	Yes	Yes			0		0	170
+127.0.0.1	root	MASTER_PORT	1	master-bin.002	170	slave-relay-bin.002	916	master-bin.002	Yes	Yes			0		0	170
 show new master for slave with master_log_file='master-bin.001' and
 master_log_pos=4 and  master_server_id=1;
 Log_name	Log_pos

mysql-test/t/rpl000017-slave.sh

-rm -f $MYSQL_TEST_DIR/var/slave-data/*relay*
+rm -f $MYSQL_TEST_DIR/var/log/*relay*
+rm -f $MYSQL_TEST_DIR/var/slave-data/relay-log.info
 cat > $MYSQL_TEST_DIR/var/slave-data/master.info <<EOF
 master-bin.001
 4

mysys/mf_iocache.c

@@ -542,7 +542,7 @@ read_append_buffer:
 
     DBUG_ASSERT(info->append_read_pos <= info->write_pos);
     /*
-      TODO: figure out if the below assert is needed or correct.
+      TODO: figure out if the assert below is needed or correct.
     */
     DBUG_ASSERT(pos_in_file == info->end_of_file); 
     copy_len=min(Count, len_in_buff);
@@ -889,6 +889,17 @@ int my_block_write(register IO_CACHE *info, const byte *Buffer, uint Count,
 
 	/* Flush write cache */
 
+#ifdef THREAD
+#define LOCK_APPEND_BUFFER if (need_append_buffer_lock) \
+  lock_append_buffer(info);
+#define UNLOCK_APPEND_BUFFER if (need_append_buffer_lock) \
+  unlock_append_buffer(info);
+#else
+#define LOCK_APPEND_BUFFER
+#define UNLOCK_APPEND_BUFFER
+#endif
+
+
 int _flush_io_cache(IO_CACHE *info, int need_append_buffer_lock)
 {
   uint length;
@@ -906,8 +917,8 @@ int _flush_io_cache(IO_CACHE *info, int need_append_buffer_lock)
       if (real_open_cached_file(info))
 	DBUG_RETURN((info->error= -1));
     }
-    if (need_append_buffer_lock)
-      lock_append_buffer(info);
+    LOCK_APPEND_BUFFER;
+    
     if ((length=(uint) (info->write_pos - info->write_buffer)))
     {
       pos_in_file=info->pos_in_file;
@@ -919,8 +930,7 @@ int _flush_io_cache(IO_CACHE *info, int need_append_buffer_lock)
 	if (my_seek(info->file,pos_in_file,MY_SEEK_SET,MYF(0)) ==
 	    MY_FILEPOS_ERROR)
 	{
-	  if (need_append_buffer_lock)
-	    unlock_append_buffer(info);
+	  UNLOCK_APPEND_BUFFER;
 	  DBUG_RETURN((info->error= -1));
 	}
 	if (!append_cache)
@@ -941,11 +951,13 @@ int _flush_io_cache(IO_CACHE *info, int need_append_buffer_lock)
         set_if_bigger(info->end_of_file,(pos_in_file+length));
       }
       else
+      {
 	info->end_of_file+=(info->write_pos-info->append_read_pos);
+	DBUG_ASSERT(info->end_of_file == my_tell(info->file,MYF(0)));
+      }
       
       info->append_read_pos=info->write_pos=info->write_buffer;
-      if (need_append_buffer_lock)
-        unlock_append_buffer(info);
+      UNLOCK_APPEND_BUFFER;
       DBUG_RETURN(info->error);
     }
   }
@@ -956,8 +968,7 @@ int _flush_io_cache(IO_CACHE *info, int need_append_buffer_lock)
     info->inited=0;
   }
 #endif
-  if (need_append_buffer_lock)
-    unlock_append_buffer(info);
+  UNLOCK_APPEND_BUFFER;
   DBUG_RETURN(0);
 }
 

mysys/mf_iocache2.c

@@ -23,10 +23,30 @@
 #include <m_string.h>
 #include <stdarg.h>
 #include <m_ctype.h>
+#include <assert.h>
+
+my_off_t my_b_append_tell(IO_CACHE* info)
+{
+  my_off_t res; 
+/* we need to lock the append buffer mutex to keep flush_io_cache()
+   from messing with the variables that we need in order to provide the
+   answer to the question.
+*/
+#ifdef THREAD
+  pthread_mutex_lock(&info->append_buffer_lock);
+#endif
+  DBUG_ASSERT(info->end_of_file - (info->append_read_pos-info->write_buffer)
+	      == my_tell(info->file,MYF(0)));
+  res = info->end_of_file + (info->write_pos-info->append_read_pos);
+#ifdef THREAD
+  pthread_mutex_unlock(&info->append_buffer_lock);
+#endif
+  return res;
+}
 
 /*
-  Fix that next read will be made at certain position
-  For write cache, make next write happen at a certain position
+  Make next read happen at the given position
+  For write cache, make next write happen at the given position
 */
 
 void my_b_seek(IO_CACHE *info,my_off_t pos)

sql/log.cc

@@ -742,11 +742,12 @@ bool MYSQL_LOG::appendv(const char* buf, uint len,...)
       error = 1;
       break;
     }
+  } while ((buf=va_arg(args,const char*)) && (len=va_arg(args,uint)));
+  
   if ((uint)my_b_append_tell(&log_file) > max_binlog_size)
   {
     new_file(1);
   }
-  } while ((buf=va_arg(args,const char*)) && (len=va_arg(args,uint)));
   
   if (!error)
     signal_update();

sql/slave.cc

@@ -1057,6 +1057,7 @@ int init_master_info(MASTER_INFO* mi, const char* master_info_fname,
   if (init_relay_log_info(&mi->rli, slave_info_fname))
     return 1;
   mi->rli.mi = mi;
+  mi->ignore_stop_event=0;
   int fd,length,error;
   MY_STAT stat_area;
   char fname[FN_REFLEN+128];
@@ -1275,10 +1276,6 @@ int flush_master_info(MASTER_INFO* mi)
   return 0;
 }
 
-/* TODO: the code below needs to be re-written almost from scratch
-   Main issue is how to find out if we have reached a certain position
-   in the master log my knowing the offset in the relay log.
- */  
 int st_relay_log_info::wait_for_pos(THD* thd, String* log_name,
 				    ulonglong log_pos)
 {
@@ -1921,6 +1918,7 @@ the slave SQL thread with \"mysqladmin start-slave\". We stopped at log \
   DBUG_RETURN(0);				// Can't return anything here
 }
 
+// We assume we already locked mi->data_lock
 static int process_io_rotate(MASTER_INFO* mi, Rotate_log_event* rev)
 {
   if (!rev->is_valid())
@@ -1941,77 +1939,112 @@ static int process_io_rotate(MASTER_INFO* mi, Rotate_log_event* rev)
     return 0;
 }
 
+// TODO: verify the issue with stop events, see if we need them at all
+// in the relay log
+// TODO: test this code before release - it has to be tested on a separte
+// setup with 3.23 master 
 static int queue_old_event(MASTER_INFO* mi, const char* buf,
 			   uint event_len)
 {
   const char* errmsg = 0;
   bool inc_pos = 1;
+  bool processed_stop_event = 0;
   Log_event* ev = Log_event::read_log_event(buf,event_len, &errmsg,
 					    1/*old format*/);
-  if (!ev)
+  if (unlikely(!ev))
   {
     sql_print_error("Read invalid event from master: '%s',\
  master could be corrupt  but a more likely cause of this is a bug",
 		    errmsg);
     return 1;
   }
+  pthread_mutex_lock(&mi->data_lock);
   ev->log_pos = mi->master_log_pos;
   switch (ev->get_type_code())
   {
   case ROTATE_EVENT:
-    if (process_io_rotate(mi,(Rotate_log_event*)ev))
+    if (unlikely(process_io_rotate(mi,(Rotate_log_event*)ev)))
     {
       delete ev;
+      pthread_mutex_unlock(&mi->data_lock);
       return 1;
     }
+    mi->ignore_stop_event=1;
     inc_pos = 0;
     break;
+  case STOP_EVENT:
+    processed_stop_event=1;
+    break;
   case LOAD_EVENT:
     // TODO: actually process it
     mi->master_log_pos += event_len;
+    delete ev;
+    pthread_mutex_unlock(&mi->data_lock);
     return 0;
-    break;
   default:
+    mi->ignore_stop_event=0;
     break;
   }
-  if (mi->rli.relay_log.append(ev))
+  if (likely(!processed_stop_event || !mi->ignore_stop_event))
+  {
+    if (unlikely(mi->rli.relay_log.append(ev)))
     {
       delete ev;
+      pthread_mutex_unlock(&mi->data_lock);
       return 1;
     }
+  }
   delete ev;
-  if (inc_pos)
+  if (likely(inc_pos))
     mi->master_log_pos += event_len;
+  if (unlikely(processed_stop_event))
+    mi->ignore_stop_event=1;
+  pthread_mutex_lock(&mi->data_lock);
   return 0;
 }
 
+// TODO: verify the issue with stop events, see if we need them at all
+// in the relay log
 int queue_event(MASTER_INFO* mi,const char* buf,uint event_len)
 {
-  int error;
+  int error=0;
   bool inc_pos = 1;
+  bool processed_stop_event = 0;
   if (mi->old_format)
     return queue_old_event(mi,buf,event_len);
+
+  pthread_mutex_lock(&mi->data_lock);
+  
   // TODO: figure out if other events in addition to Rotate
   // require special processing
   switch (buf[EVENT_TYPE_OFFSET])
   {
+  case STOP_EVENT:
+    processed_stop_event=1;
+    break;
   case ROTATE_EVENT:
   {
     Rotate_log_event rev(buf,event_len,0);
-    if (process_io_rotate(mi,&rev))
+    if (unlikely(process_io_rotate(mi,&rev)))
       return 1;
     inc_pos=0;
+    mi->ignore_stop_event=1;
     break;
   }
   default:
+    mi->ignore_stop_event=0;
     break;
   }
   
-  if (!(error = mi->rli.relay_log.appendv(buf,event_len,0)))
+  if (likely((!processed_stop_event || !mi->ignore_stop_event) &&
+	     !(error = mi->rli.relay_log.appendv(buf,event_len,0))))
   {
-    if (inc_pos)
+    if (likely(inc_pos))
       mi->master_log_pos += event_len;
   }
+  if (unlikely(processed_stop_event))
+    mi->ignore_stop_event=1;
+  pthread_mutex_unlock(&mi->data_lock);
   return error;
 }
 

sql/slave.h

@@ -240,6 +240,9 @@ typedef struct st_master_info
   int events_till_abort;
 #endif
   volatile bool abort_slave, slave_running;
+  
+  bool ignore_stop_event;
+  
   THD* io_thd;
   
   st_master_info():fd(-1),inited(0),