Final push for WL#1098:

"Add a column "Timestamp_of_last_master_event_executed" in SHOW SLAVE STATUS".
Finally this is adding
- Slave_IO_State (a copy of the State column of SHOW PROCESSLIST for the I/O thread,
so that the users, most of the time, has enough info with only SHOW SLAVE STATUS).
- Seconds_behind_master. When the slave connects to the master it does SELECT UNIX_TIMESTAMP()
on the master, computes the absolute difference between the master's and the slave's clock.
It records the timestamp of the last event executed by the SQL thread, and does a
small computation to find the number of seconds by which the slave is late.


mysql-test/r/rpl000015.result:
  result update
mysql-test/r/rpl_empty_master_crash.result:
  result update
mysql-test/r/rpl_error_ignored_table.result:
  result update
mysql-test/r/rpl_flush_log_loop.result:
  result update
mysql-test/r/rpl_loaddata.result:
  result update
mysql-test/r/rpl_log.result:
  result update
mysql-test/r/rpl_log_pos.result:
  result update
mysql-test/r/rpl_max_relay_size.result:
  result update
mysql-test/r/rpl_redirect.result:
  result update
mysql-test/r/rpl_replicate_do.result:
  result update
mysql-test/r/rpl_reset_slave.result:
  result update
mysql-test/r/rpl_rotate_logs.result:
  result update
mysql-test/r/rpl_trunc_binlog.result:
  result update
mysql-test/r/rpl_until.result:
  result update
mysql-test/t/rpl000015.test:
  update to be independant of the new column Seconds_behind_master in SHOW SLAVE STATUS
mysql-test/t/rpl_empty_master_crash.test:
  update to be independant of the new column Seconds_behind_master in SHOW SLAVE STATUS
mysql-test/t/rpl_error_ignored_table.test:
  update to be independant of the new column Seconds_behind_master in SHOW SLAVE STATUS
mysql-test/t/rpl_flush_log_loop.test:
  update to be independant of the new column Seconds_behind_master in SHOW SLAVE STATUS
mysql-test/t/rpl_loaddata.test:
  update to be independant of the new column Seconds_behind_master in SHOW SLAVE STATUS
mysql-test/t/rpl_log.test:
  update to be independant of the new column Seconds_behind_master in SHOW SLAVE STATUS
mysql-test/t/rpl_log_pos.test:
  update to be independant of the new column Seconds_behind_master in SHOW SLAVE STATUS
mysql-test/t/rpl_max_relay_size.test:
  update to be independant of the new column Seconds_behind_master in SHOW SLAVE STATUS
mysql-test/t/rpl_openssl.test:
  update to be independant of the new column Seconds_behind_master in SHOW SLAVE STATUS
mysql-test/t/rpl_redirect.test:
  update to be independant of the new column Seconds_behind_master in SHOW SLAVE STATUS
mysql-test/t/rpl_replicate_do.test:
  update to be independant of the new column Seconds_behind_master in SHOW SLAVE STATUS
mysql-test/t/rpl_reset_slave.test:
  update to be independant of the new column Seconds_behind_master in SHOW SLAVE STATUS
mysql-test/t/rpl_rotate_logs.test:
  update to be independant of the new column Seconds_behind_master in SHOW SLAVE STATUS
mysql-test/t/rpl_trunc_binlog.test:
  update to be independant of the new column Seconds_behind_master in SHOW SLAVE STATUS
mysql-test/t/rpl_until.test:
  update to be independant of the new column Seconds_behind_master in SHOW SLAVE STATUS
sql/log_event.cc:
  when the SQL thread executes an event, we record its timestamp
sql/slave.cc:
  in check_master_version() we know read the master's clock, to know the clock difference
  with the slave.
  In show_master_info() we send the state of the I/O thread, and compute the number of
  seconds by which the slave is late.
sql/slave.h:
  timestamp of the last master's event executed by the SQL thread,
  and difference between the clocks of the master and slave.
sql/sql_repl.cc:
  clear the Seconds_behind_master column of SHOW SLAVE STATUS when RESET SLAVE or CHANGE MASTER.

4 files changed, 86 insertions, 18 deletions

diff --git a/sql/log_event.cc b/sql/log_event.cc
index 2050be0e6de..ebbd0d1b373 100644
--- a/sql/log_event.cc
+++ b/sql/log_event.cc
@@ -327,6 +327,8 @@ int Log_event::exec_event(struct st_relay_log_info* rli)
     {
       rli->inc_group_relay_log_pos(get_event_len(),log_pos);
       flush_relay_log_info(rli);
+      /* if this is a fake rotate, don't record the timestamp */
+      rli->last_master_timestamp= (when) ? when : 0;
     }
   }
   return 0;
diff --git a/sql/slave.cc b/sql/slave.cc
index d1a8fe51f33..3e98386bbb1 100644
--- a/sql/slave.cc
+++ b/sql/slave.cc
@@ -73,7 +73,7 @@ static int safe_sleep(THD* thd, int sec, CHECK_KILLED_FUNC thread_killed,
 static int request_table_dump(MYSQL* mysql, const char* db, const char* table);
 static int create_table_from_dump(THD* thd, MYSQL *mysql, const char* db,
 				  const char* table_name, bool overwrite);
-static int check_master_version(MYSQL* mysql, MASTER_INFO* mi);
+static int check_master_version_and_clock(MYSQL* mysql, MASTER_INFO* mi);
 
 
 /*
@@ -1071,7 +1071,7 @@ static int init_intvar_from_file(int* var, IO_CACHE* f, int default_val)
 }
 
 
-static int check_master_version(MYSQL* mysql, MASTER_INFO* mi)
+static int get_master_version_and_clock(MYSQL* mysql, MASTER_INFO* mi)
 {
   const char* errmsg= 0;
   
@@ -1094,6 +1094,33 @@ static int check_master_version(MYSQL* mysql, MASTER_INFO* mi)
     break;
   }
 
+  MYSQL_RES *master_clock_res;
+  MYSQL_ROW master_clock_row;
+  time_t slave_clock;
+
+  if (mysql_real_query(mysql, "SELECT UNIX_TIMESTAMP()", 23))
+    errmsg= "\"SELECT UNIX_TIMESTAMP()\" failed on master"; 
+  else if (!(master_clock_res= mysql_store_result(mysql)))
+  {
+    errmsg= "Could not read the result of \"SELECT UNIX_TIMESTAMP()\" on \
+master"; 
+  }
+  else 
+  {
+    if (!(master_clock_row= mysql_fetch_row(master_clock_res)))
+      errmsg= "Could not read a row from the result of \"SELECT \
+UNIX_TIMESTAMP()\" on master"; 
+    else
+    {
+      slave_clock= time((time_t*) 0);
+      mi->clock_diff_with_master= (long) (slave_clock -
+                                          strtoul(master_clock_row[0], 0, 10));
+      DBUG_PRINT("info",("slave_clock=%lu, master_clock=%s",
+                         slave_clock, master_clock_row[0]));
+    }
+  mysql_free_result(master_clock_res);
+  }
+
   if (errmsg)
   {
     sql_print_error(errmsg);
@@ -1597,14 +1624,18 @@ void init_master_info_with_options(MASTER_INFO* mi)
     strmake(mi->ssl_key, master_ssl_key, sizeof(mi->ssl_key)-1);
 }
 
-
-void clear_last_slave_error(RELAY_LOG_INFO* rli)
+static void clear_slave_error(RELAY_LOG_INFO* rli)
 {
-  //Clear the errors displayed by SHOW SLAVE STATUS
-  rli->last_slave_error[0]=0;
-  rli->last_slave_errno=0;
+  /* Clear the errors displayed by SHOW SLAVE STATUS */
+  rli->last_slave_error[0]= 0;
+  rli->last_slave_errno= 0;
 }
 
+void clear_slave_error_timestamp(RELAY_LOG_INFO* rli)
+{
+  rli->last_master_timestamp= 0;
+  clear_slave_error(rli);
+}
 
 /*
     Reset UNTIL condition for RELAY_LOG_INFO
@@ -1908,6 +1939,8 @@ int show_master_info(THD* thd, MASTER_INFO* mi)
   Protocol *protocol= thd->protocol;
   DBUG_ENTER("show_master_info");
 
+  field_list.push_back(new Item_empty_string("Slave_IO_State",
+						     14));
   field_list.push_back(new Item_empty_string("Master_Host",
 						     sizeof(mi->host)));
   field_list.push_back(new Item_empty_string("Master_User",
@@ -1958,6 +1991,8 @@ int show_master_info(THD* thd, MASTER_INFO* mi)
                                              sizeof(mi->ssl_cipher)));
   field_list.push_back(new Item_empty_string("Master_SSL_Key", 
                                              sizeof(mi->ssl_key)));
+  field_list.push_back(new Item_return_int("Seconds_behind_master", 10,
+                                           MYSQL_TYPE_LONGLONG));
   
   if (protocol->send_fields(&field_list, 1))
     DBUG_RETURN(-1);
@@ -1970,6 +2005,8 @@ int show_master_info(THD* thd, MASTER_INFO* mi)
   
     pthread_mutex_lock(&mi->data_lock);
     pthread_mutex_lock(&mi->rli.data_lock);
+
+    protocol->store(mi->io_thd ? mi->io_thd->proc_info : "", &my_charset_bin);
     protocol->store(mi->host, &my_charset_bin);
     protocol->store(mi->user, &my_charset_bin);
     protocol->store((uint32) mi->port);
@@ -2025,7 +2062,15 @@ int show_master_info(THD* thd, MASTER_INFO* mi)
     protocol->store(mi->ssl_cert, &my_charset_bin);
     protocol->store(mi->ssl_cipher, &my_charset_bin);
     protocol->store(mi->ssl_key, &my_charset_bin);
-    
+
+    if (mi->rli.last_master_timestamp)
+      protocol->store((ulonglong) 
+                      (long)((time_t)time((time_t*) 0)
+                             - mi->rli.last_master_timestamp)
+                      - mi->clock_diff_with_master);
+    else
+      protocol->store_null();
+
     pthread_mutex_unlock(&mi->rli.data_lock);
     pthread_mutex_unlock(&mi->data_lock);
   
@@ -2068,9 +2113,10 @@ bool flush_master_info(MASTER_INFO* mi)
 st_relay_log_info::st_relay_log_info()
   :info_fd(-1), cur_log_fd(-1), save_temporary_tables(0),
    cur_log_old_open_count(0), group_master_log_pos(0), log_space_total(0),
-   ignore_log_space_limit(0), slave_skip_counter(0), abort_pos_wait(0),
-   slave_run_id(0), sql_thd(0), last_slave_errno(0), inited(0), abort_slave(0),
-   slave_running(0), until_condition(UNTIL_NONE), until_log_pos(0)
+   ignore_log_space_limit(0), last_master_timestamp(0), slave_skip_counter(0),
+   abort_pos_wait(0), slave_run_id(0), sql_thd(0), last_slave_errno(0),
+   inited(0), abort_slave(0), slave_running(0), until_condition(UNTIL_NONE),
+   until_log_pos(0)
 {
   group_relay_log_name[0]= event_relay_log_name[0]= group_master_log_name[0]= 0;
   last_slave_error[0]=0; until_log_name[0]= 0;
@@ -2776,7 +2822,7 @@ connected:
 
   thd->slave_net = &mysql->net;
   thd->proc_info = "Checking master version";
-  if (check_master_version(mysql, mi))
+  if (get_master_version_and_clock(mysql, mi))
     goto err;
   if (!mi->old_format)
   {
@@ -3057,9 +3103,13 @@ slave_begin:
   /*
     Reset errors for a clean start (otherwise, if the master is idle, the SQL
     thread may execute no Query_log_event, so the error will remain even
-    though there's no problem anymore).
+    though there's no problem anymore). Do not reset the master timestamp
+    (imagine the slave has caught everything, the STOP SLAVE and START SLAVE: as
+    we are not sure that we are going to receive a query, we want to remember
+    the last master timestamp (to say how many seconds behind we are now.
+    But the master timestamp is reset by RESET SLAVE & CHANGE MASTER.
   */
-  clear_last_slave_error(rli);
+  clear_slave_error(rli);
 
   //tell the I/O thread to take relay_log_space_limit into account from now on
   pthread_mutex_lock(&rli->log_space_lock);
diff --git a/sql/slave.h b/sql/slave.h
index 05cf7a23b0f..618b04311b9 100644
--- a/sql/slave.h
+++ b/sql/slave.h
@@ -213,6 +213,8 @@ typedef struct st_relay_log_info
   */
   int event_len;
 
+  time_t last_master_timestamp; 
+
   /*
     Needed for problems when slave stops and we want to restart it
     skipping one or more events in the master log that have caused
@@ -390,6 +392,16 @@ typedef struct st_master_info
   enum enum_binlog_formats old_format;
   volatile bool abort_slave, slave_running;
   volatile ulong slave_run_id;
+  /* 
+     The difference in seconds between the clock of the master and the clock of
+     the slave (second - first). It must be signed as it may be <0 or >0.
+     clock_diff_with_master is computed when the I/O thread starts; for this the
+     I/O thread does a SELECT UNIX_TIMESTAMP() on the master.
+     "how late the slave is compared to the master" is computed like this:
+     clock_of_slave - last_timestamp_executed_by_SQL_thread - clock_diff_with_master
+
+  */
+  long clock_diff_with_master; 
   
   st_master_info()
     :ssl(0), fd(-1),  io_thd(0), inited(0), old_format(BINLOG_FORMAT_CURRENT),
@@ -512,7 +524,7 @@ void slave_print_error(RELAY_LOG_INFO* rli, int err_code, const char* msg, ...);
 void end_slave(); /* clean up */
 void init_master_info_with_options(MASTER_INFO* mi);
 void clear_until_condition(RELAY_LOG_INFO* rli);
-void clear_last_slave_error(RELAY_LOG_INFO* rli);
+void clear_slave_error_timestamp(RELAY_LOG_INFO* rli);
 int init_master_info(MASTER_INFO* mi, const char* master_info_fname,
 		     const char* slave_info_fname,
 		     bool abort_if_no_master_info_file);
diff --git a/sql/sql_repl.cc b/sql/sql_repl.cc
index 2345355922c..5db3be7599b 100644
--- a/sql/sql_repl.cc
+++ b/sql/sql_repl.cc
@@ -878,7 +878,11 @@ int reset_slave(THD *thd, MASTER_INFO* mi)
     STATUS; before doing START SLAVE;
   */
   init_master_info_with_options(mi);
-  clear_last_slave_error(&mi->rli);
+  /* 
+     Reset errors, and master timestamp (the idea is that we forget about the
+     old master).
+  */
+  clear_slave_error_timestamp(&mi->rli);
   clear_until_condition(&mi->rli);
   
   // close master_info_file, relay_log_info_file, set mi->inited=rli->inited=0
@@ -1092,8 +1096,8 @@ int change_master(THD* thd, MASTER_INFO* mi)
 
   pthread_mutex_lock(&mi->rli.data_lock);
   mi->rli.abort_pos_wait++; /* for MASTER_POS_WAIT() to abort */
-  /* Clear the error, for a clean start. */
-  clear_last_slave_error(&mi->rli);
+  /* Clear the errors, for a clean start, and master timestamp */
+  clear_slave_error_timestamp(&mi->rli);
   clear_until_condition(&mi->rli);
   /*
     If we don't write new coordinates to disk now, then old will remain in