Bug#20685029: SLAVE IO THREAD SHOULD STOP WHEN DISK IS

FULL
Bug#21753696: MAKE SHOW SLAVE STATUS NON BLOCKING IF IO
THREAD WAITS FOR DISK SPACE

Problem:
========
Currently SHOW SLAVE STATUS blocks if IO thread waits for
disk space. This makes automation tools verifying
server health block on taking relevant action. Finally this
will create SHOW SLAVE STATUS piles.

Analysis:
=========
SHOW SLAVE STATUS hangs on mi->data_lock if relay log write
is waiting for free disk space while holding mi->data_lock.
mi->data_lock is needed to protect the format description
event (mi->format_description_event) which is accessed by
the clients running FLUSH LOGS and slave IO thread. Note
relay log writes don't need to be protected by
mi->data_lock, LOCK_log is used to protect relay log between
IO and SQL thread (see MYSQL_BIN_LOG::append_event). The
code takes mi->data_lock to protect
mi->format_description_event during relay log rotate which
might get triggered right after relay log write.

Fix:
====
Release the data_lock just for the duration of writing into
relay log.

Made change to ensure the following lock order is maintained
to avoid deadlocks.

data_lock, LOCK_log

data_lock is held during relay log rotations to protect
the description event.

5 files changed, 98 insertions, 26 deletions

diff --git a/sql/log.cc b/sql/log.cc
index 9e34532f1ac..eab9a118147 100644
--- a/sql/log.cc
+++ b/sql/log.cc
@@ -1,4 +1,4 @@
-/* Copyright (c) 2000, 2015, Oracle and/or its affiliates. All rights reserved.
+/* Copyright (c) 2000, 2016, Oracle and/or its affiliates. All rights reserved.
 
    This program is free software; you can redistribute it and/or modify
    it under the terms of the GNU General Public License as published by
@@ -37,6 +37,7 @@
 #include "log_event.h"          // Query_log_event
 #include "rpl_filter.h"
 #include "rpl_rli.h"
+#include "rpl_mi.h"
 #include "sql_audit.h"
 
 #include "sql_show.h"
@@ -4377,14 +4378,23 @@ end:
 }
 
 
-bool MYSQL_BIN_LOG::append(Log_event* ev)
+#ifdef HAVE_REPLICATION
+bool MYSQL_BIN_LOG::append(Log_event* ev,  Master_info *mi)
 {
   bool error = 0;
+  mysql_mutex_assert_owner(&mi->data_lock);
   mysql_mutex_lock(&LOCK_log);
   DBUG_ENTER("MYSQL_BIN_LOG::append");
 
   DBUG_ASSERT(log_file.type == SEQ_READ_APPEND);
   /*
+    Release data_lock by holding LOCK_log, while writing into the relay log.
+    If slave IO thread waits here for free space, we don't want
+    SHOW SLAVE STATUS to hang on mi->data_lock. Note LOCK_log mutex is
+    sufficient to block SQL thread when IO thread is updating relay log here.
+  */
+  mysql_mutex_unlock(&mi->data_lock);
+  /*
     Log_event::write() is smart enough to use my_b_write() or
     my_b_append() depending on the kind of cache we have.
   */
@@ -4398,24 +4408,50 @@ bool MYSQL_BIN_LOG::append(Log_event* ev)
   if (flush_and_sync(0))
     goto err;
   if ((uint) my_b_append_tell(&log_file) > max_size)
+  {
+    /*
+      If rotation is required we must acquire data_lock to protect
+      description_event from clients executing FLUSH LOGS in parallel.
+      In order do that we must release the existing LOCK_log so that we
+      get it once again in proper locking order to avoid dead locks.
+      i.e data_lock , LOCK_log.
+    */
+    mysql_mutex_unlock(&LOCK_log);
+    mysql_mutex_lock(&mi->data_lock);
+    mysql_mutex_lock(&LOCK_log);
     error= new_file_without_locking();
+    /*
+      After rotation release data_lock, we need the LOCK_log till we signal
+      the updation.
+    */
+    mysql_mutex_unlock(&mi->data_lock);
+  }
 err:
-  mysql_mutex_unlock(&LOCK_log);
   signal_update();				// Safe as we don't call close
+  mysql_mutex_unlock(&LOCK_log);
+  mysql_mutex_lock(&mi->data_lock);
   DBUG_RETURN(error);
 }
 
 
-bool MYSQL_BIN_LOG::appendv(const char* buf, uint len,...)
+bool MYSQL_BIN_LOG::appendv(Master_info* mi, const char* buf, uint len,...)
 {
   bool error= 0;
   DBUG_ENTER("MYSQL_BIN_LOG::appendv");
   va_list(args);
   va_start(args,len);
 
+  mysql_mutex_assert_owner(&mi->data_lock);
+  mysql_mutex_lock(&LOCK_log);
   DBUG_ASSERT(log_file.type == SEQ_READ_APPEND);
 
-  mysql_mutex_assert_owner(&LOCK_log);
+  /*
+    Release data_lock by holding LOCK_log, while writing into the relay log.
+    If slave IO thread waits here for free space, we don't want
+    SHOW SLAVE STATUS to hang on mi->data_lock. Note LOCK_log mutex is
+    sufficient to block SQL thread when IO thread is updating relay log here.
+  */
+  mysql_mutex_unlock(&mi->data_lock);
   do
   {
     if (my_b_append(&log_file,(uchar*) buf,len))
@@ -4428,13 +4464,34 @@ bool MYSQL_BIN_LOG::appendv(const char* buf, uint len,...)
   DBUG_PRINT("info",("max_size: %lu",max_size));
   if (flush_and_sync(0))
     goto err;
-  if ((uint) my_b_append_tell(&log_file) > max_size)
+  if ((uint) my_b_append_tell(&log_file) >
+      DBUG_EVALUATE_IF("rotate_slave_debug_group", 500, max_size))
+  {
+    /*
+      If rotation is required we must acquire data_lock to protect
+      description_event from clients executing FLUSH LOGS in parallel.
+      In order do that we must release the existing LOCK_log so that we
+      get it once again in proper locking order to avoid dead locks.
+      i.e data_lock , LOCK_log.
+    */
+    mysql_mutex_unlock(&LOCK_log);
+    mysql_mutex_lock(&mi->data_lock);
+    mysql_mutex_lock(&LOCK_log);
     error= new_file_without_locking();
+    /*
+      After rotation release data_lock, we need the LOCK_log till we signal
+      the updation.
+    */
+    mysql_mutex_unlock(&mi->data_lock);
+  }
 err:
   if (!error)
     signal_update();
+  mysql_mutex_unlock(&LOCK_log);
+  mysql_mutex_lock(&mi->data_lock);
   DBUG_RETURN(error);
 }
+#endif
 
 bool MYSQL_BIN_LOG::flush_and_sync(bool *synced)
 {
diff --git a/sql/log.h b/sql/log.h
index 1fc13afe7d1..7d1c3161ac2 100644
--- a/sql/log.h
+++ b/sql/log.h
@@ -1,4 +1,4 @@
-/* Copyright (c) 2005, 2012, Oracle and/or its affiliates. All rights reserved.
+/* Copyright (c) 2005, 2016, Oracle and/or its affiliates. All rights reserved.
 
    This program is free software; you can redistribute it and/or modify
    it under the terms of the GNU General Public License as published by
@@ -20,6 +20,7 @@
 #include "handler.h"                            /* my_xid */
 
 class Relay_log_info;
+class Master_info;
 
 class Format_description_log_event;
 
@@ -454,8 +455,8 @@ public:
     v stands for vector
     invoked as appendv(buf1,len1,buf2,len2,...,bufn,lenn,0)
   */
-  bool appendv(const char* buf,uint len,...);
-  bool append(Log_event* ev);
+  bool appendv(Master_info* mi, const char* buf,uint len,...);
+  bool append(Log_event* ev, Master_info* mi);
 
   void make_log_name(char* buf, const char* log_ident);
   bool is_active(const char* log_file_name);
diff --git a/sql/slave.cc b/sql/slave.cc
index d97a9cdf6e9..31037c453d3 100644
--- a/sql/slave.cc
+++ b/sql/slave.cc
@@ -1,4 +1,4 @@
-/* Copyright (c) 2000, 2015, Oracle and/or its affiliates. All rights reserved.
+/* Copyright (c) 2000, 2016, Oracle and/or its affiliates. All rights reserved.
 
    This program is free software; you can redistribute it and/or modify
    it under the terms of the GNU General Public License as published by
@@ -1660,7 +1660,7 @@ Waiting for the slave SQL thread to free enough relay log space");
 #endif
     if (rli->sql_force_rotate_relay)
     {
-      rotate_relay_log(rli->mi);
+      rotate_relay_log(rli->mi, true/*need_data_lock=true*/);
       rli->sql_force_rotate_relay= false;
     }
 
@@ -1705,7 +1705,7 @@ static void write_ignored_events_info_to_relay_log(THD *thd, Master_info *mi)
     if (likely((bool)ev))
     {
       ev->server_id= 0; // don't be ignored by slave SQL thread
-      if (unlikely(rli->relay_log.append(ev)))
+      if (unlikely(rli->relay_log.append(ev, mi)))
         mi->report(ERROR_LEVEL, ER_SLAVE_RELAY_LOG_WRITE_FAILURE,
                    ER(ER_SLAVE_RELAY_LOG_WRITE_FAILURE),
                    "failed to write a Rotate event"
@@ -3605,7 +3605,7 @@ static int process_io_create_file(Master_info* mi, Create_file_log_event* cev)
           break;
         Execute_load_log_event xev(thd,0,0);
         xev.log_pos = cev->log_pos;
-        if (unlikely(mi->rli.relay_log.append(&xev)))
+        if (unlikely(mi->rli.relay_log.append(&xev, mi)))
         {
           mi->report(ERROR_LEVEL, ER_SLAVE_RELAY_LOG_WRITE_FAILURE,
                      ER(ER_SLAVE_RELAY_LOG_WRITE_FAILURE),
@@ -3619,7 +3619,7 @@ static int process_io_create_file(Master_info* mi, Create_file_log_event* cev)
       {
         cev->block = net->read_pos;
         cev->block_len = num_bytes;
-        if (unlikely(mi->rli.relay_log.append(cev)))
+        if (unlikely(mi->rli.relay_log.append(cev, mi)))
         {
           mi->report(ERROR_LEVEL, ER_SLAVE_RELAY_LOG_WRITE_FAILURE,
                      ER(ER_SLAVE_RELAY_LOG_WRITE_FAILURE),
@@ -3634,7 +3634,7 @@ static int process_io_create_file(Master_info* mi, Create_file_log_event* cev)
         aev.block = net->read_pos;
         aev.block_len = num_bytes;
         aev.log_pos = cev->log_pos;
-        if (unlikely(mi->rli.relay_log.append(&aev)))
+        if (unlikely(mi->rli.relay_log.append(&aev, mi)))
         {
           mi->report(ERROR_LEVEL, ER_SLAVE_RELAY_LOG_WRITE_FAILURE,
                      ER(ER_SLAVE_RELAY_LOG_WRITE_FAILURE),
@@ -3713,7 +3713,7 @@ static int process_io_rotate(Master_info *mi, Rotate_log_event *rev)
     Rotate the relay log makes binlog format detection easier (at next slave
     start or mysqlbinlog)
   */
-  DBUG_RETURN(rotate_relay_log(mi) /* will take the right mutexes */);
+  DBUG_RETURN(rotate_relay_log(mi, false/*need_data_lock=false*/));
 }
 
 /*
@@ -3819,7 +3819,7 @@ static int queue_binlog_ver_1_event(Master_info *mi, const char *buf,
       Log_event::Log_event(const char* buf...) in log_event.cc).
       */
       ev->log_pos+= event_len; /* make log_pos be the pos of the end of the event */
-    if (unlikely(rli->relay_log.append(ev)))
+    if (unlikely(rli->relay_log.append(ev, mi)))
     {
       delete ev;
       mysql_mutex_unlock(&mi->data_lock);
@@ -3875,7 +3875,7 @@ static int queue_binlog_ver_3_event(Master_info *mi, const char *buf,
     inc_pos= event_len;
     break;
   }
-  if (unlikely(rli->relay_log.append(ev)))
+  if (unlikely(rli->relay_log.append(ev, mi)))
   {
     delete ev;
     mysql_mutex_unlock(&mi->data_lock);
@@ -4083,7 +4083,6 @@ static int queue_event(Master_info* mi,const char* buf, ulong event_len)
      direct master (an unsupported, useless setup!).
   */
 
-  mysql_mutex_lock(log_lock);
   s_id= uint4korr(buf + SERVER_ID_OFFSET);
   if ((s_id == ::server_id && !mi->rli.replicate_same_server_id) ||
       /*
@@ -4116,6 +4115,7 @@ static int queue_event(Master_info* mi,const char* buf, ulong event_len)
       IGNORE_SERVER_IDS it increments mi->master_log_pos
       as well as rli->group_relay_log_pos.
     */
+    mysql_mutex_lock(log_lock);
     if (!(s_id == ::server_id && !mi->rli.replicate_same_server_id) ||
         (buf[EVENT_TYPE_OFFSET] != FORMAT_DESCRIPTION_EVENT &&
          buf[EVENT_TYPE_OFFSET] != ROTATE_EVENT &&
@@ -4127,13 +4127,14 @@ static int queue_event(Master_info* mi,const char* buf, ulong event_len)
       rli->ign_master_log_pos_end= mi->master_log_pos;
     }
     rli->relay_log.signal_update(); // the slave SQL thread needs to re-check
+    mysql_mutex_unlock(log_lock);
     DBUG_PRINT("info", ("master_log_pos: %lu, event originating from %u server, ignored",
                         (ulong) mi->master_log_pos, uint4korr(buf + SERVER_ID_OFFSET)));
   }
   else
   {
     /* write the event to the relay log */
-    if (likely(!(rli->relay_log.appendv(buf,event_len,0))))
+    if (likely(!(rli->relay_log.appendv(mi, buf,event_len,0))))
     {
       mi->master_log_pos+= inc_pos;
       DBUG_PRINT("info", ("master_log_pos: %lu", (ulong) mi->master_log_pos));
@@ -4143,9 +4144,10 @@ static int queue_event(Master_info* mi,const char* buf, ulong event_len)
     {
       error= ER_SLAVE_RELAY_LOG_WRITE_FAILURE;
     }
+    mysql_mutex_lock(log_lock);
     rli->ign_master_log_name_end[0]= 0; // last event is not ignored
+    mysql_mutex_unlock(log_lock);
   }
-  mysql_mutex_unlock(log_lock);
 
 skip_relay_logging:
   
@@ -5005,11 +5007,21 @@ err:
   locks; here we don't, so this function is mainly taking locks).
   Returns nothing as we cannot catch any error (MYSQL_BIN_LOG::new_file()
   is void).
+
+  @param mi Master_info for the IO thread.
+  @param need_data_lock If true, mi->data_lock will be acquired otherwise,
+  mi->data_lock must be held by the caller.
 */
 
-int rotate_relay_log(Master_info* mi)
+int rotate_relay_log(Master_info* mi, bool need_data_lock)
 {
   DBUG_ENTER("rotate_relay_log");
+  if (need_data_lock)
+    mysql_mutex_lock(&mi->data_lock);
+  else
+  {
+    mysql_mutex_assert_owner(&mi->data_lock);
+  }
   Relay_log_info* rli= &mi->rli;
   int error= 0;
 
@@ -5044,6 +5056,8 @@ int rotate_relay_log(Master_info* mi)
   */
   rli->relay_log.harvest_bytes_written(&rli->log_space_total);
 end:
+  if (need_data_lock)
+    mysql_mutex_unlock(&mi->data_lock);
   DBUG_RETURN(error);
 }
 
diff --git a/sql/slave.h b/sql/slave.h
index 0374a5d27ae..0cf8adb0315 100644
--- a/sql/slave.h
+++ b/sql/slave.h
@@ -1,4 +1,4 @@
-/* Copyright (c) 2000, 2010, Oracle and/or its affiliates. All rights reserved.
+/* Copyright (c) 2000, 2016, Oracle and/or its affiliates. All rights reserved.
 
    This program is free software; you can redistribute it and/or modify
    it under the terms of the GNU General Public License as published by
@@ -205,7 +205,7 @@ int purge_relay_logs(Relay_log_info* rli, THD *thd, bool just_reset,
 		     const char** errmsg);
 void set_slave_thread_options(THD* thd);
 void set_slave_thread_default_charset(THD *thd, Relay_log_info const *rli);
-int rotate_relay_log(Master_info* mi);
+int rotate_relay_log(Master_info* mi, bool need_data_lock);
 int apply_event_and_update_pos(Log_event* ev, THD* thd, Relay_log_info* rli);
 
 pthread_handler_t handle_slave_io(void *arg);
diff --git a/sql/sql_reload.cc b/sql/sql_reload.cc
index 40e350c4ddd..f24f31b6399 100644
--- a/sql/sql_reload.cc
+++ b/sql/sql_reload.cc
@@ -1,4 +1,4 @@
-/* Copyright (c) 2010, 2015, Oracle and/or its affiliates. All rights reserved.
+/* Copyright (c) 2010, 2016, Oracle and/or its affiliates. All rights reserved.
 
    This program is free software; you can redistribute it and/or modify
    it under the terms of the GNU General Public License as published by
@@ -157,7 +157,7 @@ bool reload_acl_and_cache(THD *thd, unsigned long options,
   {
 #ifdef HAVE_REPLICATION
     mysql_mutex_lock(&LOCK_active_mi);
-    if (rotate_relay_log(active_mi))
+    if (rotate_relay_log(active_mi, true/*need_data_lock=true*/))
       *write_to_binlog= -1;
     mysql_mutex_unlock(&LOCK_active_mi);
 #endif