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.

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)

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;

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;

mysql-test/t/rpl_relayrotate-master.opt

+--binlog_cache_size=32768

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;

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);
     }

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);

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;

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;