bk commit into 5.1 tree (pekka:1.2599)

[Stewart Smith]

Below is the list of changes that have just been committed into a local
5.1 repository of stewart. When stewart does a push these changes will
be propagated to the main repository and, within 24 hours after the
push, to the public repository.
For information on how to access the public repository
see http://dev.mysql.com/doc/mysql/en/installing-source-tree.html

ChangeSet@stripped, 2007-07-31 21:50:01+10:00, pekka@stripped +2 -0
  [PATCH] 01_gcp_timer.diff
  
  time gcp duration in master and
  send info event if it is excessive
  
  Index: storage/ndb/src/kernel/blocks/dbdih/Dbdih.hpp
  ===================================================================

  storage/ndb/src/kernel/blocks/dbdih/Dbdih.hpp@stripped, 2007-07-31 10:00:00+10:00, pekka@stripped +6 -0
    01_gcp_timer.diff

  storage/ndb/src/kernel/blocks/dbdih/DbdihMain.cpp@stripped, 2007-07-31 10:00:00+10:00, pekka@stripped +14 -0
    01_gcp_timer.diff

# This is a BitKeeper patch.  What follows are the unified diffs for the
# set of deltas contained in the patch.  The rest of the patch, the part
# that BitKeeper cares about, is below these diffs.
# User:	pekka
# Host:	willster.(none)
# Root:	/home/stewart/Documents/MySQL/5.1/telco-6.2

--- 1.42/storage/ndb/src/kernel/blocks/dbdih/Dbdih.hpp	2007-06-27 19:23:21 +10:00
+++ 1.43/storage/ndb/src/kernel/blocks/dbdih/Dbdih.hpp	2007-07-31 10:00:00 +10:00
@@ -1283,6 +1283,12 @@
     
     Uint32 m_expectedNextWord;
   } c_copyGCISlave;
+
+  /*
+   * Time GCP in master DIH.
+   * Later can measure per node or per protocol parts.
+   */
+  MicroSecondTimer gcp_timer_start;
   
   /*------------------------------------------------------------------------*/
   /*       THIS VARIABLE IS USED TO KEEP TRACK OF THE STATE OF LOCAL        */

--- 1.136/storage/ndb/src/kernel/blocks/dbdih/DbdihMain.cpp	2007-06-27 19:23:21 +10:00
+++ 1.137/storage/ndb/src/kernel/blocks/dbdih/DbdihMain.cpp	2007-07-31 10:00:00 +10:00
@@ -8011,6 +8011,8 @@
   signal->theData[1] = cnewgcp;
   sendSignal(CMVMI_REF, GSN_EVENT_REP, signal, 2, JBB);
 
+  NdbTick_getMicroTimer(&gcp_timer_start);
+
   CRASH_INSERTION(7000);
   cnewgcp++;
   signal->setTrace(TestOrd::TraceGlobalCheckpoint);
@@ -8530,6 +8532,18 @@
     signal->theData[0] = NDB_LE_GlobalCheckpointCompleted; //Event type
     signal->theData[1] = coldgcp;
     sendSignal(CMVMI_REF, GSN_EVENT_REP, signal, 2, JBB);    
+
+    {
+      MicroSecondTimer stop;
+      NdbTick_getMicroTimer(&stop);
+      NDB_TICKS ticks = NdbTick_getMicrosPassed(gcp_timer_start, stop);
+      Uint32 ms = ticks / 1000;
+      // random formula to report excessive duration
+      bool report = ms > 3000 * (1 + cgcpDelay / 1000);
+      if (report)
+        infoEvent("GCP %u duration %u ms (config %u ms)",
+                  coldgcp, ms, cgcpDelay);
+    }
 
     c_newest_restorable_gci = coldgcp;