bk commit into 5.1 tree (pekka:1.2580)

[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-08-01 14:45:46+10:00, pekka@stripped +3 -0
  [PATCH] time GCP protocol on each node (in 3 parts) and send info event if time is "excessive" or once if error 7901 is inserted
  
  Index: telco-6.1/storage/ndb/src/kernel/blocks/dbdih/DbdihMain.cpp
  ===================================================================

  storage/ndb/src/kernel/blocks/dbdih/DbdihMain.cpp@stripped, 2007-08-01 12:07:06+10:00, pekka@stripped +38 -1
    time GCP protocol on each node (in 3 parts) and send info event if time is "excessive" or once if error 7901 is inserted

  storage/ndb/src/kernel/blocks/dblqh/DblqhMain.cpp@stripped, 2007-08-01 12:07:06+10:00, pekka@stripped +9 -0
    time GCP protocol on each node (in 3 parts) and send info event if time is "excessive" or once if error 7901 is inserted

  storage/ndb/src/kernel/vm/GlobalData.hpp@stripped, 2007-08-01 12:07:06+10:00, pekka@stripped +16 -0
    time GCP protocol on each node (in 3 parts) and send info event if time is "excessive" or once if error 7901 is inserted

# 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.1.17

--- 1.117/storage/ndb/src/kernel/blocks/dbdih/DbdihMain.cpp	2007-06-26 23:39:33 +10:00
+++ 1.118/storage/ndb/src/kernel/blocks/dbdih/DbdihMain.cpp	2007-08-01 12:07:06 +10:00
@@ -754,6 +754,12 @@
     jam();
     return;
   }
+#ifdef GCP_TIMER_HACK
+  if (reason == CopyGCIReq::GLOBAL_CHECKPOINT) {
+    jam();
+    NdbTick_getMicroTimer(&globalData.gcp_timer_copygci[0]);
+  }
+#endif
 
   /* ----------------------------------------------------------------------- */
   /*     WE START BY TRYING TO OPEN THE FIRST RESTORABLE GCI FILE.           */
@@ -8069,7 +8075,9 @@
     sendSignalWithDelay(CMVMI_REF, GSN_NDB_TAMPER, signal, 3000, 1);
     return;
   }
-  
+#ifdef GCP_TIMER_HACK
+  NdbTick_getMicroTimer(&globalData.gcp_timer_commit[0]);
+#endif
   signal->theData[0] = cownNodeId;
   signal->theData[1] = gci;  
   sendSignal(retRef, GSN_GCP_PREPARECONF, signal, 2, JBA);
@@ -8116,6 +8124,10 @@
     return;
   }
 
+#ifdef GCP_TIMER_HACK
+  NdbTick_getMicroTimer(&globalData.gcp_timer_commit[1]);
+#endif
+
   cgcpParticipantState = GCP_PARTICIPANT_TC_FINISHED;
   signal->theData[0] = cownNodeId;
   signal->theData[1] = coldgcp;
@@ -8542,6 +8554,31 @@
     EXECUTE_DIRECT(LGMAN, GSN_SUB_GCP_COMPLETE_REP, signal, 
 		   SubGcpCompleteRep::SignalLength);
     jamEntry();
+
+#ifdef GCP_TIMER_HACK
+    NdbTick_getMicroTimer(&globalData.gcp_timer_copygci[1]);
+
+    // this is last timer point so we send local report here
+    {
+      const GlobalData& g = globalData;
+      Uint32 ms_commit = NdbTick_getMicrosPassed(
+          g.gcp_timer_commit[0], g.gcp_timer_commit[1]) / 1000;
+      Uint32 ms_save = NdbTick_getMicrosPassed(
+          g.gcp_timer_save[0], g.gcp_timer_save[1]) / 1000;
+      Uint32 ms_copygci = NdbTick_getMicrosPassed(
+          g.gcp_timer_copygci[0], g.gcp_timer_copygci[1]) / 1000;
+
+      Uint32 ms_total = ms_commit + ms_save + ms_copygci;
+
+      // random formula to report excessive duration
+      bool report =
+        ERROR_INSERTED_CLEAR(7901) ||
+        ms_total > 3000 * (1 + cgcpDelay / 1000);
+      if (report)
+        infoEvent("GCP %u ms: total:%u commit:%u save:%u copygci:%u",
+            coldgcp, ms_total, ms_commit, ms_save, ms_copygci);
+    }
+#endif
   }
   
   jam();

--- 1.156/storage/ndb/src/kernel/blocks/dblqh/DblqhMain.cpp	2007-08-01 11:48:37 +10:00
+++ 1.157/storage/ndb/src/kernel/blocks/dblqh/DblqhMain.cpp	2007-08-01 12:07:06 +10:00
@@ -12104,6 +12104,10 @@
     return;
   }
 
+#ifdef GCP_TIMER_HACK
+  NdbTick_getMicroTimer(&globalData.gcp_timer_save[0]);
+#endif
+
   ccurrentGcprec = 0;
   gcpPtr.i = ccurrentGcprec;
   ptrCheckGuard(gcpPtr, cgcprecFileSize, gcpRecord);
@@ -12325,6 +12329,11 @@
       return;
     }//if
   }//for
+
+#ifdef GCP_TIMER_HACK
+  NdbTick_getMicroTimer(&globalData.gcp_timer_save[1]);
+#endif
+
   GCPSaveConf * const saveConf = (GCPSaveConf *)&signal->theData[0];
   saveConf->dihPtr = localGcpPtr.p->gcpUserptr;
   saveConf->nodeId = getOwnNodeId();

--- 1.10/storage/ndb/src/kernel/vm/GlobalData.hpp	2007-01-24 16:20:36 +11:00
+++ 1.11/storage/ndb/src/kernel/vm/GlobalData.hpp	2007-08-01 12:07:06 +10:00
@@ -26,6 +26,11 @@
 #include <NodeInfo.hpp>
 #include "ArrayPool.hpp"
 
+#define GCP_TIMER_HACK
+#ifdef GCP_TIMER_HACK
+#include <NdbTick.h>
+#endif
+
 class SimulatedBlock;
 
 enum  restartStates {initial_state, 
@@ -82,6 +87,17 @@
 public:
   ArrayPool<GlobalPage> m_global_page_pool;
   ArrayPool<GlobalPage> m_shared_page_pool;
+
+#ifdef GCP_TIMER_HACK
+  // timings are local to the node
+
+  // from prepare to commit (DIH, TC)
+  MicroSecondTimer gcp_timer_commit[2];
+  // from GCP_SAVEREQ to GCP_SAVECONF (LQH)
+  MicroSecondTimer gcp_timer_save[2];
+  // sysfile update (DIH)
+  MicroSecondTimer gcp_timer_copygci[2];
+#endif
 };
 
 extern GlobalData globalData;