mysql-test/mysql-test-run

cleanup - remove unneeded daeamon restarts
sql/log_event.cc
    fixed bug - do not confuse confused slaves even further if they try to 
    read less than LOG_EVENT_HEADER_LEN before the end of file
sql/mysqlbinlog.cc
    give error if constructor fails
sql/mysqld.cc
    --disconnect-slave-event-count for replication debugging
sql/slave.cc
    --disconnect-slave-event-count
    cleanup to remove unneeded sleeps when things go wrong - sleep only 
    when we have to
sql/slave.h
    --disconnect-slave-event-count

test cases for ALTER TABLE ORDER BY and replication offset off by 22 
confusion mystery bug (both pass)


mysql-test/mysql-test-run:
  cleanup - remove unneeded daeamon restarts
sql/log_event.cc:
  fixed bug - do not confuse confused slaves even further if they try to 
  read less than LOG_EVENT_HEADER_LEN before the end of file
sql/mysqlbinlog.cc:
  give error if constructor fails
sql/mysqld.cc:
  --disconnect-slave-event-count for replication debugging
sql/slave.cc:
  --disconnect-slave-event-count
  cleanup to remove unneeded sleeps when things go wrong - sleep only 
  when we have to
sql/slave.h:
  --disconnect-slave-event-count
sql/sql_repl.cc:
  added unknown error

mysql-test/mysql-test-run

@@ -278,6 +278,7 @@ start_master()
 
 start_slave()
 {
+    [ x$SKIP_SLAVE = x1 ] && return
     [ -d $GCOV_SLAVE_SRC ] && cd $GCOV_SLAVE_SRC
     slave_args="--no-defaults --server-id=2 \
 	    --master-user=root \
@@ -362,7 +363,7 @@ run_testcase ()
  tname=`$ECHO $tname | $CUT -d . -f 1`
  master_opt_file=$TESTDIR/$tname-master.opt
  slave_opt_file=$TESTDIR/$tname-slave.opt
-
+ SKIP_SLAVE=`$EXPR \( match $tname rpl \) = 0`
  
  if [ -f $master_opt_file ] ;
  then
@@ -443,7 +444,9 @@ run_testcase ()
 
 mysql_install_db
 
-if [ -z $DO_GDB ]
+#do not automagically start deamons if we are in gdb or running only one test
+#case
+if [ -z $DO_GDB ] && [ -z $1 ]
 then
  $SETCOLOR_NORMAL && $ECHO -n "Starting mysqld for Testing" 
  mysql_start

mysql-test/r/3.23/alt000001.result

@@ -0,0 +1,5 @@
+n	
+3	
+9	
+10	
+12	

mysql-test/r/3.23/rpl000010.result

@@ -0,0 +1,3 @@
+n	
+1	
+2	

mysql-test/t/3.23/alt000001.test

@@ -0,0 +1,6 @@
+use test;
+drop table if exists x;
+create table x (n int);
+insert into x values(9),(3),(12),(10);
+alter table x order by n;
+@r/3.23/alt000001.result select * from x;

mysql-test/t/3.23/rpl000010-slave.opt

@@ -0,0 +1 @@
+--disconnect-slave-event-count=1 

mysql-test/t/3.23/rpl000010.test

@@ -0,0 +1,13 @@
+#this tests the offset off by 22 mystery bug
+#must run slave with --disconnect-slave-event-count=1 --master-connect-retry=1
+source t/include/master-slave.inc;
+connection slave;
+drop table if exists foo;
+connection master;
+drop table if exists foo;
+create table foo (n int not null auto_increment primary key);
+insert into foo values(NULL);
+insert into foo values(2);
+connection slave;
+sleep 5;
+@r/3.23/rpl000010.result select n from foo;

sql/log_event.cc

@@ -81,7 +81,8 @@ int Log_event::read_log_event(IO_CACHE* file, String* packet,
     // if the read hits eof, we must report it as eof
     // so the caller will know it can go into cond_wait to be woken up
     // on the next update to the log
-    return file->error >= 0 ? LOG_READ_EOF: LOG_READ_IO;
+    if(!file->error) return LOG_READ_EOF;
+    return file->error > 0 ? LOG_READ_TRUNC: LOG_READ_IO;
   }
   data_len = uint4korr(buf + EVENT_LEN_OFFSET);
   if (data_len < LOG_EVENT_HEADER_LEN || data_len > MAX_EVENT_LEN)

sql/mysqlbinlog.cc

@@ -361,6 +361,8 @@ static void dump_local_log_entries(const char* logname)
 	die("Could not read entry at offset %ld : Error in log format or \
 read error",
 	    my_b_tell(file));
+      else
+	die("Could not construct event object");
       break;
     }
     if (rec_count >= offset)

sql/mysqld.cc

@@ -2231,7 +2231,8 @@ enum options {
 	       OPT_REPLICATE_REWRITE_DB, OPT_SERVER_ID, OPT_SKIP_SLAVE_START,
 	       OPT_SKIP_INNOBASE,OPT_SAFEMALLOC_MEM_LIMIT,
 	       OPT_REPLICATE_DO_TABLE, OPT_REPLICATE_IGNORE_TABLE,
-	       OPT_REPLICATE_WILD_DO_TABLE, OPT_REPLICATE_WILD_IGNORE_TABLE
+	       OPT_REPLICATE_WILD_DO_TABLE, OPT_REPLICATE_WILD_IGNORE_TABLE,
+	       OPT_DISCONNECT_SLAVE_EVENT_COUNT
 };
 
 static struct option long_options[] = {
@@ -2287,6 +2288,10 @@ static struct option long_options[] = {
   {"master-info-file",      required_argument, 0, (int) OPT_MASTER_INFO_FILE},
   {"myisam-recover",	    optional_argument, 0, (int) OPT_MYISAM_RECOVER},
   {"memlock",		    no_argument,       0, (int) OPT_MEMLOCK},
+    // needs to be available for the test case to pass in non-debugging mode
+    // is a no-op
+  {"disconnect-slave-event-count",      required_argument, 0,
+     (int) OPT_DISCONNECT_SLAVE_EVENT_COUNT},
 #if !defined(DBUG_OFF) && defined(SAFEMALLOC)
   {"safemalloc-mem-limit",  required_argument, 0, (int)
      OPT_SAFEMALLOC_MEM_LIMIT},
@@ -2888,6 +2893,12 @@ static void get_options(int argc,char **argv)
       if (optarg && optarg[0])
 	opt_bin_logname=my_strdup(optarg,MYF(0));
       break;
+      // needs to be handled (as no-op) in non-debugging mode for test suite
+    case (int)OPT_DISCONNECT_SLAVE_EVENT_COUNT:
+#ifndef DBUG_OFF      
+      disconnect_slave_event_count = atoi(optarg);
+#endif      
+      break;
     case (int) OPT_LOG_SLAVE_UPDATES:
       opt_log_slave_updates = 1;
       break;

sql/slave.cc

@@ -30,7 +30,11 @@ DYNAMIC_ARRAY replicate_wild_do_table, replicate_wild_ignore_table;
 bool do_table_inited = 0, ignore_table_inited = 0;
 bool wild_do_table_inited = 0, wild_ignore_table_inited = 0;
 bool table_rules_on = 0;
-
+#ifndef DBUG_OFF
+int disconnect_slave_event_count = 0;
+static int events_till_disconnect = -1;
+static int stuck_count = 0;
+#endif
 
 
 static inline void skip_load_data_infile(NET* net);
@@ -668,6 +672,11 @@ static uint read_event(MYSQL* mysql, MASTER_INFO *mi)
   // being in the interrupted state :-)
   // my_real_read() will time us out
   // we check if we were told to die, and if not, try reading again
+#ifndef DBUG_OFF
+  if(disconnect_slave_event_count && !(events_till_disconnect--))
+    return packet_error;      
+#endif
+  
   while (!abort_loop && !abort_slave && len == packet_error && read_errno == EINTR )
   {
     len = mc_net_safe_read(mysql);
@@ -970,6 +979,8 @@ pthread_handler_decl(handle_slave,arg __attribute__((unused)))
   pthread_mutex_unlock(&LOCK_slave);
   
   int error = 1;
+  bool retried_once = 0;
+  ulonglong last_failed_pos = 0;
   
   my_thread_init(); // needs to be up here, otherwise we get a coredump
   // trying to use DBUG_ stuff
@@ -1008,13 +1019,21 @@ pthread_handler_decl(handle_slave,arg __attribute__((unused)))
 	  
 	  thd->proc_info = "waiting to reconnect after a failed dump request";
 	  if(mysql->net.vio)
-	    vio_close(mysql->net.vio); 
-	  safe_sleep(thd, glob_mi.connect_retry);
+	    vio_close(mysql->net.vio);
+	  // first time retry immediately, assuming that we can recover
+	  // right away - if first time fails, sleep between re-tries
+	  // hopefuly the admin can fix the problem sometime
+	  if(retried_once)
+	    safe_sleep(thd, glob_mi.connect_retry);
+	  else
+	    retried_once = 1;
+	  
 	  if(slave_killed(thd))
 	      goto err;
 
 	  thd->proc_info = "reconnecting after a failed dump request";
-
+          sql_print_error("Slave: failed dump request, reconnecting to \
+try again, master_log_pos=%ld", last_failed_pos = glob_mi.pos );
 	  safe_reconnect(thd, mysql, &glob_mi);
 	  if(slave_killed(thd))
 	      goto err;
@@ -1025,7 +1044,6 @@ pthread_handler_decl(handle_slave,arg __attribute__((unused)))
 
       while(!slave_killed(thd))
 	{
-          bool reset = 0;
 	  thd->proc_info = "reading master update";
 	  uint event_len = read_event(mysql, &glob_mi);
 	  if(slave_killed(thd))
@@ -1035,19 +1053,22 @@ pthread_handler_decl(handle_slave,arg __attribute__((unused)))
 	  {
 	    thd->proc_info = "waiting to reconnect after a failed read";
 	    if(mysql->net.vio)
- 	      vio_close(mysql->net.vio); 
-	    safe_sleep(thd, glob_mi.connect_retry);
+ 	      vio_close(mysql->net.vio);
+	    if(retried_once) // punish repeat offender with sleep
+	      safe_sleep(thd, glob_mi.connect_retry);
+	    else
+	      retried_once = 1; 
+	    
 	    if(slave_killed(thd))
 	      goto err;
 	    thd->proc_info = "reconnecting after a failed read";
+	    sql_print_error("Slave: Failed reading log event, \
+reconnecting to retry, master_log_pos=%ld", last_failed_pos = glob_mi.pos);
 	    safe_reconnect(thd, mysql, &glob_mi);
 	    if(slave_killed(thd))
 	      goto err;
-	    reset = 1;
-	  }
-	  
-	  if(reset)
 	    break;
+	  }
 	  
 	  thd->proc_info = "processing master log event"; 
 	  if(exec_event(thd, &mysql->net, &glob_mi, event_len))
@@ -1059,6 +1080,28 @@ pthread_handler_decl(handle_slave,arg __attribute__((unused)))
 	      // abort the slave thread, when the problem is fixed, the user
 	      // should restart the slave with mysqladmin start-slave
 	    }
+	  
+	  // successful exec with offset advance,
+	  // the slave repents and his sins are forgiven!
+	  if(glob_mi.pos > last_failed_pos)
+	    {
+	     retried_once = 0;
+#ifndef DBUG_OFF
+	     stuck_count = 0;
+#endif
+	    }
+#ifndef DBUG_OFF
+	  else
+	    {
+	      stuck_count++;
+	    // show a little mercy, allow slave to read one more event
+	       // before cutting him off - otherwise he gets stuck
+	       // on Invar events, since they do not advance the offset
+	       // immediately
+	      if(stuck_count > 2)
+	        events_till_disconnect++;
+	    }
+#endif	  
 
 	}
     }
@@ -1086,6 +1129,9 @@ pthread_handler_decl(handle_slave,arg __attribute__((unused)))
 static void safe_connect(THD* thd, MYSQL* mysql, MASTER_INFO* mi)
   // will try to connect until successful
 {
+#ifndef DBUG_OFF
+  events_till_disconnect = disconnect_slave_event_count;
+#endif  
   while(!slave_killed(thd) &&
 	!mc_mysql_connect(mysql, mi->host, mi->user, mi->password, 0,
 			  mi->port, 0, 0))
@@ -1107,12 +1153,15 @@ static void safe_reconnect(THD* thd, MYSQL* mysql, MASTER_INFO* mi)
 {
   mi->pending = 0; // if we lost connection after reading a state set event
   // we will be re-reading it, so pending needs to be cleared
+#ifndef DBUG_OFF
+  events_till_disconnect = disconnect_slave_event_count;
+#endif
   while(!slave_killed(thd) && mc_mysql_reconnect(mysql))
   {
-    sql_print_error(
-		    "Slave thread: error connecting to master:%s, retry in %d sec",
+    sql_print_error("Slave thread: error connecting to master:\
+%s, retry in %d sec",
 		    mc_mysql_error(mysql), mi->connect_retry);
-    safe_sleep(thd, mi->connect_retry);
+     safe_sleep(thd, mi->connect_retry);
   }
   
 }

sql/slave.h

@@ -94,6 +94,10 @@ extern bool do_table_inited, ignore_table_inited,
 	    wild_do_table_inited, wild_ignore_table_inited;
 extern bool table_rules_on;
 
+#ifndef DBUG_OFF
+extern int disconnect_slave_event_count ;
+#endif
+
 // the master variables are defaults read from my.cnf or command line
 extern uint master_port, master_connect_retry;
 extern my_string master_user, master_password, master_host,

sql/sql_repl.cc

@@ -309,6 +309,9 @@ sweepstakes if you report the bug";
       case LOG_READ_TRUNC:
 	errmsg = "binlog truncated in the middle of event";
 	break;
+      default:
+	errmsg = "unknown error reading log event on the master";
+	break;
       }
       goto err;
     }