#At file:///home/jonas/src/telco-7.0/ based on revid:jonas@stripped
4447 jonas oreland 2011-06-09
ndb - improve DBUG_REDO printouts
modified:
storage/ndb/src/kernel/blocks/dblqh/DblqhMain.cpp
=== modified file 'storage/ndb/src/kernel/blocks/dblqh/DblqhMain.cpp'
--- a/storage/ndb/src/kernel/blocks/dblqh/DblqhMain.cpp 2011-05-31 08:28:58 +0000
+++ b/storage/ndb/src/kernel/blocks/dblqh/DblqhMain.cpp 2011-06-09 08:20:13 +0000
@@ -14238,6 +14238,15 @@ retry:
sltLogPartPtr.p->logTailMbyte =
sltLogFilePtr.p->logLastPrepRef[tsltMbyte] & 65535;
+ if (DEBUG_REDO)
+ {
+ ndbout_c("part: %u setLogTail(gci: %u): file: %u mb: %u",
+ sltLogPartPtr.p->logPartNo,
+ keepGci,
+ sltLogPartPtr.p->logTailFileNo,
+ sltLogPartPtr.p->logTailMbyte);
+ }
+
bool tailmoved = !(ToldTailFileNo == sltLogPartPtr.p->logTailFileNo &&
ToldTailMByte == sltLogPartPtr.p->logTailMbyte);
@@ -16169,11 +16178,28 @@ void Dblqh::writeFileDescriptor(Signal*
arrGuard(logFilePtr.p->currentMbyte, clogFileSize);
if (DEBUG_REDO)
{
- ndbout_c("part: %u file: %u setting logMaxGciCompleted[%u] = %u",
- logPartPtr.p->logPartNo,
- logFilePtr.p->fileNo,
- logFilePtr.p->currentMbyte,
- logPartPtr.p->logPartNewestCompletedGCI);
+ printf("part: %u file: %u setting logMaxGciCompleted[%u] = %u logMaxGciStarted[%u]: %u lastPrepRef[%u]: ",
+ logPartPtr.p->logPartNo,
+ logFilePtr.p->fileNo,
+ logFilePtr.p->currentMbyte,
+ logPartPtr.p->logPartNewestCompletedGCI,
+ logFilePtr.p->currentMbyte,
+ cnewestGci,
+ logFilePtr.p->currentMbyte);
+ if (logPartPtr.p->firstLogTcrec == RNIL)
+ {
+ ndbout_c("file: %u mb: %u (RNIL)",
+ logFilePtr.p->fileNo,
+ logFilePtr.p->currentMbyte);
+ }
+ else
+ {
+ wfdTcConnectptr.i = logPartPtr.p->firstLogTcrec;
+ ptrCheckGuard(wfdTcConnectptr, ctcConnectrecFileSize, tcConnectionrec);
+ ndbout_c("file: %u mb: %u",
+ wfdTcConnectptr.p->logStartFileNo,
+ wfdTcConnectptr.p->logStartPageNo >> ZTWOLOG_NO_PAGES_IN_MBYTE);
+ }
}
logFilePtr.p->logMaxGciCompleted[logFilePtr.p->currentMbyte] =
logPartPtr.p->logPartNewestCompletedGCI;
@@ -16346,10 +16372,11 @@ void Dblqh::writeSinglePage(Signal* sign
if (DEBUG_REDO)
{
- ndbout_c("writeSingle 1 page at part: %u file: %u pos: %u",
+ ndbout_c("writeSingle 1 page at part: %u file: %u page: %u (mb: %u)",
logPartPtr.p->logPartNo,
logFilePtr.p->fileNo,
- pageNo);
+ pageNo,
+ pageNo >> ZTWOLOG_NO_PAGES_IN_MBYTE);
}
}//Dblqh::writeSinglePage()
@@ -16452,8 +16479,10 @@ void Dblqh::readSrLastMbyteLab(Signal* s
logPartPtr.p->lastMbyte = logFilePtr.p->currentMbyte - 1;
if (DEBUG_REDO)
{
- ndbout_c("readSrLastMbyteLab part: %u lastMbyte: %u",
- logPartPtr.p->logPartNo, logPartPtr.p->lastMbyte);
+ ndbout_c("readSrLastMbyteLab part: %u file: %u lastMbyte: %u",
+ logPartPtr.p->logPartNo,
+ logFilePtr.p->fileNo,
+ logPartPtr.p->lastMbyte);
}
}//if
}//if
@@ -17503,6 +17532,17 @@ void Dblqh::execSrCompletedLab(Signal* s
systemErrorLab(signal, __LINE__);
return;
}//if
+
+ if (DEBUG_REDO)
+ {
+ ndbout_c("part: %u srLogLimits SR_FOURTH_PHASE %u-%u (file: %u mb: %u)",
+ logPartPtr.p->logPartNo,
+ logPartPtr.p->logStartGci,
+ logPartPtr.p->logLastGci,
+ logPartPtr.p->lastLogfile,
+ logPartPtr.p->lastMbyte);
+ }
+
signal->theData[0] = ZSR_LOG_LIMITS;
signal->theData[1] = logPartPtr.i;
signal->theData[2] = logPartPtr.p->lastLogfile;
@@ -17689,6 +17729,15 @@ void Dblqh::srGciLimits(Signal* signal)
jam();
ptrAss(logPartPtr, logPartRecord);
logPartPtr.p->logExecState = LogPartRecord::LES_SEARCH_STOP;
+ if (DEBUG_REDO)
+ {
+ ndbout_c("part: %u srLogLimits (srGciLimits) %u-%u (file: %u mb: %u)",
+ logPartPtr.p->logPartNo,
+ logPartPtr.p->logStartGci,
+ logPartPtr.p->logLastGci,
+ logPartPtr.p->lastLogfile,
+ logPartPtr.p->lastMbyte);
+ }
signal->theData[0] = ZSR_LOG_LIMITS;
signal->theData[1] = logPartPtr.i;
signal->theData[2] = logPartPtr.p->lastLogfile;
@@ -17720,22 +17769,34 @@ void Dblqh::srLogLimits(Signal* signal)
* ----------------------------------------------------------------------- */
while(true) {
ndbrequire(tmbyte < clogFileSize);
- if (logPartPtr.p->logExecState == LogPartRecord::LES_SEARCH_STOP) {
- if (logFilePtr.p->logMaxGciCompleted[tmbyte] <= logPartPtr.p->logLastGci) {
+ if (logPartPtr.p->logExecState == LogPartRecord::LES_SEARCH_STOP)
+ {
+ if (logFilePtr.p->logMaxGciCompleted[tmbyte] <= logPartPtr.p->logLastGci)
+ {
jam();
- /* --------------------------------------------------------------------
- * WE ARE STEPPING BACKWARDS FROM MBYTE TO MBYTE. THIS IS THE FIRST
- * MBYTE WHICH IS TO BE INCLUDED IN THE LOG EXECUTION. THE STOP GCI
- * HAS NOT BEEN COMPLETED BEFORE THIS MBYTE. THUS THIS MBYTE HAVE
- * TO BE EXECUTED.
- * ------------------------------------------------------------------- */
+ /* --------------------------------------------------------------------
+ * WE ARE STEPPING BACKWARDS FROM MBYTE TO MBYTE. THIS IS THE FIRST
+ * MBYTE WHICH IS TO BE INCLUDED IN THE LOG EXECUTION. THE STOP GCI
+ * HAS NOT BEEN COMPLETED BEFORE THIS MBYTE. THUS THIS MBYTE HAVE
+ * TO BE EXECUTED.
+ * ------------------------------------------------------------------ */
logPartPtr.p->stopLogfile = logFilePtr.i;
logPartPtr.p->stopMbyte = tmbyte;
logPartPtr.p->logExecState = LogPartRecord::LES_SEARCH_START;
+ if (DEBUG_REDO)
+ {
+ ndbout_c("part: %u srLogLimits found stop pos file: %u mb: %u logMaxGciCompleted[tmbyte]: %u (lastGci: %u)",
+ logPartPtr.p->logPartNo,
+ logFilePtr.p->fileNo,
+ tmbyte,
+ logFilePtr.p->logMaxGciCompleted[tmbyte],
+ logPartPtr.p->logLastGci);
+ }
}//if
else if (DEBUG_REDO)
{
- ndbout_c("SKIP part: %u file: %u mb: %u logMaxGciCompleted: %u >= %u",
+ ndbout_c("SEARCH STOP SKIP part: %u file: %u mb: %u "
+ "logMaxGciCompleted: %u > %u",
logPartPtr.p->logPartNo,
logFilePtr.p->fileNo,
tmbyte,
@@ -17743,28 +17804,53 @@ void Dblqh::srLogLimits(Signal* signal)
logPartPtr.p->logLastGci);
}
}//if
- /* ------------------------------------------------------------------------
- * WHEN WE HAVEN'T FOUND THE STOP MBYTE IT IS NOT NECESSARY TO LOOK FOR THE
- * START MBYTE. THE REASON IS THE FOLLOWING LOGIC CHAIN:
- * MAX_GCI_STARTED >= MAX_GCI_COMPLETED >= LAST_GCI >= START_GCI
- * THUS MAX_GCI_STARTED >= START_GCI. THUS MAX_GCI_STARTED < START_GCI CAN
- * NOT BE TRUE AS WE WILL CHECK OTHERWISE.
- * ----------------------------------------------------------------------- */
- if (logPartPtr.p->logExecState == LogPartRecord::LES_SEARCH_START) {
- if (logFilePtr.p->logMaxGciStarted[tmbyte] < logPartPtr.p->logStartGci) {
+ /* ------------------------------------------------------------------------
+ * WHEN WE HAVEN'T FOUND THE STOP MBYTE IT IS NOT NECESSARY TO LOOK FOR THE
+ * START MBYTE. THE REASON IS THE FOLLOWING LOGIC CHAIN:
+ * MAX_GCI_STARTED >= MAX_GCI_COMPLETED >= LAST_GCI >= START_GCI
+ * THUS MAX_GCI_STARTED >= START_GCI. THUS MAX_GCI_STARTED < START_GCI CAN
+ * NOT BE TRUE AS WE WILL CHECK OTHERWISE.
+ * ---------------------------------------------------------------------- */
+ if (logPartPtr.p->logExecState == LogPartRecord::LES_SEARCH_START)
+ {
+ if (logFilePtr.p->logMaxGciStarted[tmbyte] < logPartPtr.p->logStartGci)
+ {
jam();
- /* --------------------------------------------------------------------
- * WE HAVE NOW FOUND THE START OF THE EXECUTION OF THE LOG.
- * WE STILL HAVE TO MOVE IT BACKWARDS TO ALSO INCLUDE THE
- * PREPARE RECORDS WHICH WERE STARTED IN A PREVIOUS MBYTE.
- * ------------------------------------------------------------------- */
+ /* --------------------------------------------------------------------
+ * WE HAVE NOW FOUND THE START OF THE EXECUTION OF THE LOG.
+ * WE STILL HAVE TO MOVE IT BACKWARDS TO ALSO INCLUDE THE
+ * PREPARE RECORDS WHICH WERE STARTED IN A PREVIOUS MBYTE.
+ * ------------------------------------------------------------------ */
+ if (DEBUG_REDO)
+ {
+ ndbout_c("part: %u srLogLimits found start pos file: %u mb: %u logMaxGciStarted[tmbyte]: %u (startGci: %u)",
+ logPartPtr.p->logPartNo,
+ logFilePtr.p->fileNo,
+ tmbyte,
+ logFilePtr.p->logMaxGciCompleted[tmbyte],
+ logPartPtr.p->logStartGci);
+ ndbout_c("part: %u srLogLimits lastPrepRef => file: %u mb: %u",
+ logPartPtr.p->logPartNo,
+ logFilePtr.p->logLastPrepRef[tmbyte] >> 16,
+ logFilePtr.p->logLastPrepRef[tmbyte] & 65535);
+ }
tlastPrepRef = logFilePtr.p->logLastPrepRef[tmbyte];
logPartPtr.p->startMbyte = tlastPrepRef & 65535;
LogFileRecordPtr locLogFilePtr;
findLogfile(signal, tlastPrepRef >> 16, logPartPtr, &locLogFilePtr);
logPartPtr.p->startLogfile = locLogFilePtr.i;
logPartPtr.p->logExecState = LogPartRecord::LES_EXEC_LOG;
- }//if
+ }
+ else if (DEBUG_REDO)
+ {
+ ndbout_c("SEARCH START SKIP part: %u file: %u mb: %u "
+ "logMaxGciCompleted: %u >= %u",
+ logPartPtr.p->logPartNo,
+ logFilePtr.p->fileNo,
+ tmbyte,
+ logFilePtr.p->logMaxGciStarted[tmbyte],
+ logPartPtr.p->logStartGci);
+ }
}//if
if (logPartPtr.p->logExecState != LogPartRecord::LES_EXEC_LOG) {
if (tmbyte == 0) {
@@ -18250,11 +18336,12 @@ void Dblqh::execSr(Signal* signal)
logWord = readLogword(signal);
if (DEBUG_REDO)
{
- ndbout_c("found gci: %u part: %u file: %u page: %u",
+ ndbout_c("found gci: %u part: %u file: %u page: %u (mb: %u)",
logWord,
logPartPtr.p->logPartNo,
logFilePtr.p->fileNo,
- logFilePtr.p->currentFilepage);
+ logFilePtr.p->currentFilepage,
+ logFilePtr.p->currentFilepage >> ZTWOLOG_NO_PAGES_IN_MBYTE);
}
if (logWord == logPartPtr.p->logLastGci)
{
@@ -19879,11 +19966,12 @@ void Dblqh::completedLogPage(Signal* sig
if (DEBUG_REDO)
{
- ndbout_c("writing %d pages at part: %u file: %u pos: %u",
+ ndbout_c("writing %d pages at part: %u file: %u page: %u (mb: %u)",
twlpNoPages,
logPartPtr.p->logPartNo,
logFilePtr.p->fileNo,
- logFilePtr.p->filePosition);
+ logFilePtr.p->filePosition,
+ logFilePtr.p->filePosition >> ZTWOLOG_NO_PAGES_IN_MBYTE);
}
if (twlpType == ZNORMAL) {
@@ -21089,11 +21177,12 @@ void Dblqh::readExecLog(Signal* signal)
if (DEBUG_REDO)
{
- ndbout_c("readExecLog %u page at part: %u file: %u pos: %u",
+ ndbout_c("readExecLog %u page at part: %u file: %u page: %u (mb: %u)",
lfoPtr.p->noPagesRw,
logPartPtr.p->logPartNo,
logFilePtr.p->fileNo,
- logPartPtr.p->execSrStartPageNo);
+ logPartPtr.p->execSrStartPageNo,
+ logPartPtr.p->execSrStartPageNo >> ZTWOLOG_NO_PAGES_IN_MBYTE);
}
}//Dblqh::readExecLog()
@@ -21160,11 +21249,12 @@ void Dblqh::readExecSr(Signal* signal)
if (DEBUG_REDO)
{
- ndbout_c("readExecSr %u page at part: %u file: %u pos: %u",
+ ndbout_c("readExecSr %u page at part: %u file: %u page: %u (mb: %u)",
8,
logPartPtr.p->logPartNo,
logFilePtr.p->fileNo,
- tresPageid);
+ tresPageid,
+ tresPageid >> ZTWOLOG_NO_PAGES_IN_MBYTE);
}
}//Dblqh::readExecSr()
@@ -21322,10 +21412,11 @@ void Dblqh::readSinglePage(Signal* signa
if (DEBUG_REDO)
{
- ndbout_c("readSinglePage 1 page at part: %u file: %u pos: %u",
+ ndbout_c("readSinglePage 1 page at part: %u file: %u page: %u (mb: %u)",
logPartPtr.p->logPartNo,
logFilePtr.p->fileNo,
- pageNo);
+ pageNo,
+ pageNo >> ZTWOLOG_NO_PAGES_IN_MBYTE);
}
}//Dblqh::readSinglePage()
@@ -21854,11 +21945,12 @@ void Dblqh::writeCompletedGciLog(Signal*
if (DEBUG_REDO)
{
- ndbout_c("writeCompletedGciLog gci: %u part: %u file: %u page: %u",
+ ndbout_c("writeCompletedGciLog gci: %u part: %u file: %u page: %u (mb: %u)",
cnewestCompletedGci,
logPartPtr.p->logPartNo,
logFilePtr.p->fileNo,
- logFilePtr.p->currentFilepage);
+ logFilePtr.p->currentFilepage,
+ logFilePtr.p->currentFilepage >> ZTWOLOG_NO_PAGES_IN_MBYTE);
}
writeLogWord(signal, ZCOMPLETED_GCI_TYPE);
@@ -21904,10 +21996,11 @@ void Dblqh::writeDirty(Signal* signal, U
if (DEBUG_REDO)
{
- ndbout_c("writeDirty 1 page at part: %u file: %u pos: %u",
+ ndbout_c("writeDirty 1 page at part: %u file: %u page: %u (mb: %u)",
logPartPtr.p->logPartNo,
logFilePtr.p->fileNo,
- logPartPtr.p->prevFilepage);
+ logPartPtr.p->prevFilepage,
+ logPartPtr.p->prevFilepage >> ZTWOLOG_NO_PAGES_IN_MBYTE);
}
}//Dblqh::writeDirty()
Attachment: [text/bzr-bundle] bzr/jonas@mysql.com-20110609082013-5zmmzk41inqav0pp.bundle
| Thread |
|---|
| • bzr commit into mysql-5.1-telco-7.0 branch (jonas:4447) | jonas oreland | 9 Jun |
