WL#775 "Add status variable identifying binlog_cache_size shortage"

Added two status variables: 
  binlog_cache_use - counts number of transactions that used somehow
    transaction temporary binary log.
  binlog_cache_disk_use - counts number of transactions that required
    disk I/O for storing info in this this binary log.


include/my_sys.h:
  Added disk_writes member to the IO_CACHE structure for counting number
  of times when IO_CACHE was forced to write to disk.
mysql-test/r/rpl_relayrotate.result:
  Fixed test result since added test for binlog_cache_use and 
  binlog_cache_disk_use status variables.
mysql-test/t/rpl_relayrotate.test:
  Added test for binlog_cache_use and binlog_cache_disk_use status 
  variables.
  Now dropping t1 table on master too.
mysys/mf_iocache.c:
  Added disk_writes member to the IO_CACHE structure for counting number
  of times when IO_CACHE was forced to write to disk.
sql/handler.cc:
  Added support for binlog_cache_use and binlog_cache_disk_use status
  variable. First one is incremented if transaction used somehow 
  transaction temporary binary log (doesn't matter in memory only or 
  with writes to disk), the second one is incremented if this binary 
  log was flushed to disk at some point.
sql/mysql_priv.h:
  Added declaration of status variables binlog_cache_use and 
  binlog_cache_disk_use.
sql/mysqld.cc:
  Added status variables binlog_cache_use and binlog_cache_disk_use.
BitKeeper/etc/logging_ok:
  Logging to logging@openlogging.org accepted

9 files changed, 77 insertions, 3 deletions

diff --git a/BitKeeper/etc/logging_ok b/BitKeeper/etc/logging_ok
index 1391f1e0a60..4067304c8e1 100644
--- a/BitKeeper/etc/logging_ok
+++ b/BitKeeper/etc/logging_ok
@@ -28,6 +28,7 @@ carsten@tsort.bitbybit.dk
 davida@isil.mysql.com
 dlenev@brandersnatch.localdomain
 dlenev@build.mysql.com
+dlenev@jabberwock.localdomain
 dlenev@mysql.com
 gerberb@ou800.zenez.com
 gluh@gluh.(none)
diff --git a/include/my_sys.h b/include/my_sys.h
index a97ddcce40d..8beaa00eb16 100644
--- a/include/my_sys.h
+++ b/include/my_sys.h
@@ -412,6 +412,11 @@ typedef struct st_io_cache		/* Used when cacheing files */
   IO_CACHE_CALLBACK pre_read;
   IO_CACHE_CALLBACK post_read;
   IO_CACHE_CALLBACK pre_close;
+  /*
+    Counts the number of times, when we were forced to use disk. We use it to
+    increase the binlog_cache_disk_use status variable.
+  */
+  ulong disk_writes;
   void* arg;				/* for use by pre/post_read */
   char *file_name;			/* if used with 'open_cached_file' */
   char *dir,*prefix;
diff --git a/mysql-test/r/rpl_relayrotate.result b/mysql-test/r/rpl_relayrotate.result
index bf9bbbb9b93..96ec06a69aa 100644
--- a/mysql-test/r/rpl_relayrotate.result
+++ b/mysql-test/r/rpl_relayrotate.result
@@ -16,4 +16,19 @@ master_pos_wait('master-bin.001',3000)>=0
 select * from t1 where a=8000;
 a
 8000
+show status like "binlog_cache_use";
+Variable_name	Value
+Binlog_cache_use	1
+show status like "binlog_cache_disk_use";
+Variable_name	Value
+Binlog_cache_disk_use	1
+begin;
+delete from t1;
+commit;
+show status like "binlog_cache_use";
+Variable_name	Value
+Binlog_cache_use	2
+show status like "binlog_cache_disk_use";
+Variable_name	Value
+Binlog_cache_disk_use	1
 drop table t1;
diff --git a/mysql-test/t/rpl_relayrotate-master.opt b/mysql-test/t/rpl_relayrotate-master.opt
new file mode 100644
index 00000000000..4cb927540bf
--- /dev/null
+++ b/mysql-test/t/rpl_relayrotate-master.opt
@@ -0,0 +1 @@
+--binlog_cache_size=32768
diff --git a/mysql-test/t/rpl_relayrotate.test b/mysql-test/t/rpl_relayrotate.test
index 0e198d23517..ca3bff81608 100644
--- a/mysql-test/t/rpl_relayrotate.test
+++ b/mysql-test/t/rpl_relayrotate.test
@@ -58,6 +58,24 @@ start slave;
 select master_pos_wait('master-bin.001',3000)>=0;
 select * from t1 where a=8000;
 
+connection master;
+
+# binlog_cache_use and binlog_cache_disk_use status vars test
+# This test uses the previous test. Namely, it needs the long 
+# transaction that adds 8000 lines to the t1 table.
+
+show status like "binlog_cache_use";
+show status like "binlog_cache_disk_use";
+
+# transaction which should not be flushed to disk and so should not
+# increase binlog_cache_disk_use
+begin;
+delete from t1;
+commit;
+
+show status like "binlog_cache_use";
+show status like "binlog_cache_disk_use";
+
 # The following DROP is a very important cleaning task:
 # imagine the next test is run with --skip-innodb: it will do
 # DROP TABLE IF EXISTS t1; but this will delete the frm and leave
@@ -68,3 +86,7 @@ select * from t1 where a=8000;
 # InnoDB: Error: table t1 already exists in InnoDB internal
 # InnoDB: data dictionary. Have you deleted the .frm file etc
 drop table t1;
+# wait until this drop is executed on slave
+save_master_pos;
+connection slave;
+sync_with_master;
diff --git a/mysys/mf_iocache.c b/mysys/mf_iocache.c
index 288071f7361..530721a79ad 100644
--- a/mysys/mf_iocache.c
+++ b/mysys/mf_iocache.c
@@ -152,6 +152,7 @@ int init_io_cache(IO_CACHE *info, File file, uint cachesize,
   info->alloced_buffer = 0;
   info->buffer=0;
   info->seek_not_done= test(file >= 0);
+  info->disk_writes= 0;
 #ifdef THREAD
   info->share=0;
 #endif
@@ -1153,6 +1154,7 @@ int my_b_flush_io_cache(IO_CACHE *info, int need_append_buffer_lock)
       }
 
       info->append_read_pos=info->write_pos=info->write_buffer;
+      ++info->disk_writes;
       UNLOCK_APPEND_BUFFER;
       DBUG_RETURN(info->error);
     }
diff --git a/sql/handler.cc b/sql/handler.cc
index 38b95424637..ddf2e68db47 100644
--- a/sql/handler.cc
+++ b/sql/handler.cc
@@ -405,6 +405,16 @@ int ha_commit_trans(THD *thd, THD_TRANS* trans)
 	my_b_tell(&thd->transaction.trans_log))
     {
       mysql_bin_log.write(thd, &thd->transaction.trans_log, 1);
+      statistic_increment(binlog_cache_use, &LOCK_status);
+      if (thd->transaction.trans_log.disk_writes != 0)
+      {
+        /* 
+          We have to do this after addition of trans_log to main binlog since
+          this operation can cause flushing of end of trans_log to disk. 
+        */
+        statistic_increment(binlog_cache_disk_use, &LOCK_status);
+        thd->transaction.trans_log.disk_writes= 0;
+      }
       reinit_io_cache(&thd->transaction.trans_log,
 		      WRITE_CACHE, (my_off_t) 0, 0, 1);
       thd->transaction.trans_log.end_of_file= max_binlog_cache_size;
@@ -492,10 +502,23 @@ int ha_rollback_trans(THD *thd, THD_TRANS *trans)
          Update the binary log with a BEGIN/ROLLBACK block if we have cached some
          queries and we updated some non-transactional table. Such cases should
          be rare (updating a non-transactional table inside a transaction...).
+         Count disk writes to trans_log in any case.
       */
-      if (unlikely((thd->options & OPTION_STATUS_NO_TRANS_UPDATE) &&
-                   my_b_tell(&thd->transaction.trans_log)))
-        mysql_bin_log.write(thd, &thd->transaction.trans_log, 0);
+      if (my_b_tell(&thd->transaction.trans_log))
+      {
+        if (unlikely(thd->options & OPTION_STATUS_NO_TRANS_UPDATE))
+          mysql_bin_log.write(thd, &thd->transaction.trans_log, 0);
+        statistic_increment(binlog_cache_use, &LOCK_status);
+        if (thd->transaction.trans_log.disk_writes != 0)
+        {
+          /* 
+            We have to do this after addition of trans_log to main binlog since
+            this operation can cause flushing of end of trans_log to disk. 
+          */
+          statistic_increment(binlog_cache_disk_use, &LOCK_status);
+          thd->transaction.trans_log.disk_writes= 0;
+        }
+      }
       /* Flushed or not, empty the binlog cache */
       reinit_io_cache(&thd->transaction.trans_log,
                       WRITE_CACHE, (my_off_t) 0, 0, 1);
diff --git a/sql/mysql_priv.h b/sql/mysql_priv.h
index 4fd41b7bd66..a979ef137ae 100644
--- a/sql/mysql_priv.h
+++ b/sql/mysql_priv.h
@@ -791,6 +791,7 @@ extern ulonglong log_10_int[20];
 extern ulonglong keybuff_size;
 extern ulong refresh_version,flush_version, thread_id,query_id,opened_tables;
 extern ulong created_tmp_tables, created_tmp_disk_tables, bytes_sent;
+extern ulong binlog_cache_use, binlog_cache_disk_use;
 extern ulong aborted_threads,aborted_connects;
 extern ulong delayed_insert_timeout;
 extern ulong delayed_insert_limit, delayed_queue_size;
diff --git a/sql/mysqld.cc b/sql/mysqld.cc
index d602c44c8f9..308f50c3eb0 100644
--- a/sql/mysqld.cc
+++ b/sql/mysqld.cc
@@ -297,6 +297,7 @@ ulong select_range_check_count, select_range_count, select_scan_count;
 ulong select_full_range_join_count,select_full_join_count;
 ulong specialflag=0,opened_tables=0,created_tmp_tables=0,
       created_tmp_disk_tables=0;
+ulong binlog_cache_use= 0, binlog_cache_disk_use= 0;
 ulong max_connections,max_used_connections,
       max_connect_errors, max_user_connections = 0;
 ulong thread_id=1L,current_pid;
@@ -4719,6 +4720,8 @@ The minimum value for this variable is 4096.",
 struct show_var_st status_vars[]= {
   {"Aborted_clients",          (char*) &aborted_threads,        SHOW_LONG},
   {"Aborted_connects",         (char*) &aborted_connects,       SHOW_LONG},
+  {"Binlog_cache_disk_use",    (char*) &binlog_cache_disk_use,  SHOW_LONG},
+  {"Binlog_cache_use",         (char*) &binlog_cache_use,       SHOW_LONG},
   {"Bytes_received",           (char*) &bytes_received,         SHOW_LONG},
   {"Bytes_sent",               (char*) &bytes_sent,             SHOW_LONG},
   {"Com_admin_commands",       (char*) &com_other,		SHOW_LONG},
@@ -5013,6 +5016,7 @@ static void mysql_init_variables(void)
   filesort_merge_passes= select_range_check_count= select_range_count= 0;
   select_scan_count= select_full_range_join_count= select_full_join_count= 0;
   specialflag= opened_tables= created_tmp_tables= created_tmp_disk_tables= 0;
+  binlog_cache_use=  binlog_cache_disk_use= 0;
   max_used_connections= slow_launch_threads = 0;
   max_sort_char= 0;
   mysqld_user= mysqld_chroot= opt_init_file= opt_bin_logname = 0;