Skip to content

M
MariaDB
Commit 12542536 authored by tomas@poseidon.mysql.com's avatar tomas@poseidon.mysql.com
Browse files
Options

make sure some printouts in ndbd out file is done with g_eventLogger

parent 0a450519
Hide whitespace changes
Inline Side-by-side
Showing with 71 additions and 66 deletions
ndb/src/kernel/blocks/dbdih/DbdihMain.cpp
View file @ 12542536
......@@ -1786,8 +1786,8 @@ void Dbdih::execSTART_PERMREQ(Signal* signal)
return;
}//if
if (getNodeStatus(nodeId) != NodeRecord::DEAD){
ndbout << "nodeStatus in START_PERMREQ = "
<< (Uint32) getNodeStatus(nodeId) << endl;
g_eventLogger.error("nodeStatus in START_PERMREQ = %u",
(Uint32) getNodeStatus(nodeId));
ndbrequire(false);
}//if
......@@ -4029,9 +4029,9 @@ void Dbdih::checkCopyTab(NodeRecordPtr failedNodePtr)
jam();
break;
default:
ndbout_c("outstanding gsn: %s(%d)",
getSignalName(c_nodeStartMaster.m_outstandingGsn),
c_nodeStartMaster.m_outstandingGsn);
g_eventLogger.error("outstanding gsn: %s(%d)",
getSignalName(c_nodeStartMaster.m_outstandingGsn),
c_nodeStartMaster.m_outstandingGsn);
ndbrequire(false);
}
......@@ -4472,9 +4472,10 @@ void Dbdih::failedNodeLcpHandling(Signal* signal, NodeRecordPtr failedNodePtr)
failedNodePtr.p->activeStatus = Sysfile::NS_NotActive_NotTakenOver;
break;
default:
ndbout << "activeStatus = " << (Uint32) failedNodePtr.p->activeStatus;
ndbout << " at failure after NODE_FAILREP of node = ";
ndbout << failedNodePtr.i << endl;
g_eventLogger.error("activeStatus = %u "
"at failure after NODE_FAILREP of node = %u",
(Uint32) failedNodePtr.p->activeStatus,
failedNodePtr.i);
ndbrequire(false);
break;
}//switch
......@@ -4629,7 +4630,7 @@ Dbdih::startLcpMasterTakeOver(Signal* signal, Uint32 nodeId){
/**
* Node failure during master take over...
*/
ndbout_c("Nodefail during master take over");
g_eventLogger.info("Nodefail during master take over");
}
setLocalNodefailHandling(signal, nodeId, NF_LCP_TAKE_OVER);
......@@ -4869,7 +4870,8 @@ void Dbdih::execMASTER_GCPCONF(Signal* signal)
if (latestLcpId > SYSFILE->latestLCP_ID) {
jam();
#if 0
ndbout_c("Dbdih: Setting SYSFILE->latestLCP_ID to %d", latestLcpId);
g_eventLogger.info("Dbdih: Setting SYSFILE->latestLCP_ID to %d",
latestLcpId);
SYSFILE->latestLCP_ID = latestLcpId;
#endif
SYSFILE->keepGCI = oldestKeepGci;
......@@ -5528,7 +5530,7 @@ Dbdih::checkLocalNodefailComplete(Signal* signal, Uint32 failedNodeId,
if (ERROR_INSERTED(7030))
{
ndbout_c("Reenable GCP_PREPARE");
g_eventLogger.info("Reenable GCP_PREPARE");
CLEAR_ERROR_INSERT_VALUE;
}
......@@ -5701,7 +5703,7 @@ Dbdih::sendMASTER_LCPCONF(Signal * signal){
c_lcpState.setLcpStatus(LCP_STATUS_IDLE, __LINE__);
#if 0
if(c_copyGCISlave.m_copyReason == CopyGCIReq::LOCAL_CHECKPOINT){
ndbout_c("Dbdih: Also resetting c_copyGCISlave");
g_eventLogger.info("Dbdih: Also resetting c_copyGCISlave");
c_copyGCISlave.m_copyReason = CopyGCIReq::IDLE;
c_copyGCISlave.m_expectedNextWord = 0;
}
......@@ -5790,7 +5792,7 @@ Dbdih::sendMASTER_LCPCONF(Signal * signal){
if(c_lcpState.lcpStatus == LCP_TAB_SAVED){
#ifdef VM_TRACE
ndbout_c("Sending extra GSN_LCP_COMPLETE_REP to new master");
g_eventLogger.info("Sending extra GSN_LCP_COMPLETE_REP to new master");
#endif
sendLCP_COMPLETE_REP(signal);
}
......@@ -5946,7 +5948,7 @@ void Dbdih::execMASTER_LCPCONF(Signal* signal)
nodePtr.p->lcpStateAtTakeOver = lcpState;
#ifdef VM_TRACE
ndbout_c("MASTER_LCPCONF");
g_eventLogger.info("MASTER_LCPCONF");
printMASTER_LCP_CONF(stdout, &signal->theData[0], 0, 0);
#endif
......@@ -6023,7 +6025,7 @@ void Dbdih::MASTER_LCPhandling(Signal* signal, Uint32 failedNodeId)
// protocol.
/* --------------------------------------------------------------------- */
#ifdef VM_TRACE
ndbout_c("MASTER_LCPhandling:: LMTOS_ALL_IDLE -> checkLcpStart");
g_eventLogger.info("MASTER_LCPhandling:: LMTOS_ALL_IDLE -> checkLcpStart");
#endif
checkLcpStart(signal, __LINE__);
break;
......@@ -6034,7 +6036,7 @@ void Dbdih::MASTER_LCPhandling(Signal* signal, Uint32 failedNodeId)
// protocol by calculating the keep gci and storing the new lcp id.
/* --------------------------------------------------------------------- */
#ifdef VM_TRACE
ndbout_c("MASTER_LCPhandling:: LMTOS_COPY_ONGOING -> storeNewLcpId");
g_eventLogger.info("MASTER_LCPhandling:: LMTOS_COPY_ONGOING -> storeNewLcpId");
#endif
if (c_lcpState.lcpStatus == LCP_STATUS_ACTIVE) {
jam();
......@@ -6045,7 +6047,7 @@ void Dbdih::MASTER_LCPhandling(Signal* signal, Uint32 failedNodeId)
/*---------------------------------------------------------------------*/
Uint32 lcpId = SYSFILE->latestLCP_ID;
#ifdef VM_TRACE
ndbout_c("Decreasing latestLCP_ID from %d to %d", lcpId, lcpId - 1);
g_eventLogger.info("Decreasing latestLCP_ID from %d to %d", lcpId, lcpId - 1);
#endif
SYSFILE->latestLCP_ID--;
}//if
......@@ -6062,10 +6064,10 @@ void Dbdih::MASTER_LCPhandling(Signal* signal, Uint32 failedNodeId)
* complete before finalising the LCP process.
* ------------------------------------------------------------------ */
#ifdef VM_TRACE
ndbout_c("MASTER_LCPhandling:: LMTOS_ALL_ACTIVE -> "
"startLcpRoundLoopLab(table=%u, fragment=%u)",
c_lcpMasterTakeOverState.minTableId,
c_lcpMasterTakeOverState.minFragId);
g_eventLogger.info("MASTER_LCPhandling:: LMTOS_ALL_ACTIVE -> "
"startLcpRoundLoopLab(table=%u, fragment=%u)",
c_lcpMasterTakeOverState.minTableId,
c_lcpMasterTakeOverState.minFragId);
#endif
c_lcpState.keepGci = SYSFILE->keepGCI;
......@@ -7376,8 +7378,8 @@ void Dbdih::checkGcpStopLab(Signal* signal)
if (cgcpSameCounter == 1200) {
jam();
#ifdef VM_TRACE
ndbout << "System crash due to GCP Stop in state = ";
ndbout << (Uint32) cgcpStatus << endl;
g_eventLogger.error("System crash due to GCP Stop in state = %u",
(Uint32) cgcpStatus);
#endif
crashSystemAtGcpStop(signal);
return;
......@@ -7390,8 +7392,8 @@ void Dbdih::checkGcpStopLab(Signal* signal)
if (cgcpSameCounter == 1200) {
jam();
#ifdef VM_TRACE
ndbout << "System crash due to GCP Stop in state = ";
ndbout << (Uint32) cgcpStatus << endl;
g_eventLogger.error("System crash due to GCP Stop in state = %u",
(Uint32) cgcpStatus);
#endif
crashSystemAtGcpStop(signal);
return;
......@@ -7582,7 +7584,7 @@ void Dbdih::GCP_SAVEhandling(Signal* signal, Uint32 nodeId)
getNodeState().startLevel == NodeState::SL_STARTED){
jam();
#if 0
ndbout_c("Dbdih: Clearing initial start ongoing");
g_eventLogger.info("Dbdih: Clearing initial start ongoing");
#endif
Sysfile::clearInitialStartOngoing(SYSFILE->systemRestartBits);
}
......@@ -7601,7 +7603,7 @@ void Dbdih::execGCP_PREPARE(Signal* signal)
if (ERROR_INSERTED(7030))
{
cgckptflag = true;
ndbout_c("Delayed GCP_PREPARE 5s");
g_eventLogger.info("Delayed GCP_PREPARE 5s");
sendSignalWithDelay(reference(), GSN_GCP_PREPARE, signal, 5000,
signal->getLength());
return;
......@@ -7621,7 +7623,7 @@ void Dbdih::execGCP_PREPARE(Signal* signal)
if (ERROR_INSERTED(7031))
{
ndbout_c("Crashing delayed in GCP_PREPARE 3s");
g_eventLogger.info("Crashing delayed in GCP_PREPARE 3s");
signal->theData[0] = 9999;
sendSignalWithDelay(CMVMI_REF, GSN_NDB_TAMPER, signal, 3000, 1);
return;
......@@ -8136,7 +8138,7 @@ void Dbdih::initLcpLab(Signal* signal, Uint32 senderRef, Uint32 tableId)
* This is LCP master takeover
*/
#ifdef VM_TRACE
ndbout_c("initLcpLab aborted due to LCP master takeover - 1");
g_eventLogger.info("initLcpLab aborted due to LCP master takeover - 1");
#endif
c_lcpState.setLcpStatus(LCP_STATUS_IDLE, __LINE__);
sendMASTER_LCPCONF(signal);
......@@ -8149,7 +8151,7 @@ void Dbdih::initLcpLab(Signal* signal, Uint32 senderRef, Uint32 tableId)
* Master take over but has not yet received MASTER_LCPREQ
*/
#ifdef VM_TRACE
ndbout_c("initLcpLab aborted due to LCP master takeover - 2");
g_eventLogger.info("initLcpLab aborted due to LCP master takeover - 2");
#endif
return;
}
......@@ -9380,9 +9382,10 @@ void Dbdih::checkTcCounterLab(Signal* signal)
{
CRASH_INSERTION(7009);
if (c_lcpState.lcpStatus != LCP_STATUS_IDLE) {
ndbout << "lcpStatus = " << (Uint32) c_lcpState.lcpStatus;
ndbout << "lcpStatusUpdatedPlace = " <<
c_lcpState.lcpStatusUpdatedPlace << endl;
g_eventLogger.error("lcpStatus = %u"
"lcpStatusUpdatedPlace = %d",
(Uint32) c_lcpState.lcpStatus,
c_lcpState.lcpStatusUpdatedPlace);
ndbrequire(false);
return;
}//if
......@@ -9935,9 +9938,8 @@ void Dbdih::execLCP_FRAG_REP(Signal* signal)
if(tabPtr.p->tabStatus == TabRecord::TS_DROPPING){
jam();
ndbout_c("TS_DROPPING - Neglecting to save Table: %d Frag: %d - ",
tableId,
fragId);
g_eventLogger.info("TS_DROPPING - Neglecting to save Table: %d Frag: %d - ",
tableId, fragId);
} else {
jam();
/**
......@@ -10065,7 +10067,7 @@ void Dbdih::findReplica(ReplicaRecordPtr& replicaPtr,
};
#ifdef VM_TRACE
ndbout_c("Fragment Replica(node=%d) not found", nodeId);
g_eventLogger.info("Fragment Replica(node=%d) not found", nodeId);
replicaPtr.i = fragPtrP->oldStoredReplicas;
while(replicaPtr.i != RNIL){
ptrCheckGuard(replicaPtr, creplicaFileSize, replicaRecord);
......@@ -10078,9 +10080,9 @@ void Dbdih::findReplica(ReplicaRecordPtr& replicaPtr,
}//if
};
if(replicaPtr.i != RNIL){
ndbout_c("...But was found in oldStoredReplicas");
g_eventLogger.info("...But was found in oldStoredReplicas");
} else {
ndbout_c("...And wasn't found in oldStoredReplicas");
g_eventLogger.info("...And wasn't found in oldStoredReplicas");
}
#endif
ndbrequire(false);
......@@ -10114,8 +10116,8 @@ Dbdih::reportLcpCompletion(const LcpFragRep* lcpReport)
ndbrequire(replicaPtr.p->lcpOngoingFlag == true);
if(lcpNo != replicaPtr.p->nextLcp){
ndbout_c("lcpNo = %d replicaPtr.p->nextLcp = %d",
lcpNo, replicaPtr.p->nextLcp);
g_eventLogger.error("lcpNo = %d replicaPtr.p->nextLcp = %d",
lcpNo, replicaPtr.p->nextLcp);
ndbrequire(false);
}
ndbrequire(lcpNo == replicaPtr.p->nextLcp);
......@@ -10150,7 +10152,7 @@ Dbdih::reportLcpCompletion(const LcpFragRep* lcpReport)
// Not all fragments in table have been checkpointed.
/* ----------------------------------------------------------------- */
if(0)
ndbout_c("reportLcpCompletion: fragment %d not ready", fid);
g_eventLogger.info("reportLcpCompletion: fragment %d not ready", fid);
return false;
}//if
}//for
......@@ -10267,7 +10269,7 @@ void Dbdih::execLCP_COMPLETE_REP(Signal* signal)
jamEntry();
#if 0
ndbout_c("LCP_COMPLETE_REP");
g_eventLogger.info("LCP_COMPLETE_REP");
printLCP_COMPLETE_REP(stdout,
signal->getDataPtr(),
signal->length(), number());
......@@ -10353,7 +10355,7 @@ void Dbdih::allNodesLcpCompletedLab(Signal* signal)
if(c_lcpMasterTakeOverState.state != LMTOS_IDLE){
jam();
#ifdef VM_TRACE
ndbout_c("Exiting from allNodesLcpCompletedLab");
g_eventLogger.info("Exiting from allNodesLcpCompletedLab");
#endif
return;
}
......@@ -10582,14 +10584,14 @@ void Dbdih::crashSystemAtGcpStop(Signal* signal)
infoEvent("Detected GCP stop...sending kill to %s",
c_GCP_SAVEREQ_Counter.getText());
ndbout_c("Detected GCP stop...sending kill to %s",
c_GCP_SAVEREQ_Counter.getText());
g_eventLogger.error("Detected GCP stop...sending kill to %s",
c_GCP_SAVEREQ_Counter.getText());
return;
}
case GCP_SAVE_LQH_FINISHED:
ndbout_c("m_copyReason: %d m_waiting: %d",
c_copyGCIMaster.m_copyReason,
c_copyGCIMaster.m_waiting);
g_eventLogger.error("m_copyReason: %d m_waiting: %d",
c_copyGCIMaster.m_copyReason,
c_copyGCIMaster.m_waiting);
break;
case GCP_READY: // shut up lint
case GCP_PREPARE_SENT:
......@@ -10597,11 +10599,11 @@ void Dbdih::crashSystemAtGcpStop(Signal* signal)
break;
}
ndbout_c("c_copyGCISlave: sender{Data, Ref} %d %x reason: %d nextWord: %d",
c_copyGCISlave.m_senderData,
c_copyGCISlave.m_senderRef,
c_copyGCISlave.m_copyReason,
c_copyGCISlave.m_expectedNextWord);
g_eventLogger.error("c_copyGCISlave: sender{Data, Ref} %d %x reason: %d nextWord: %d",
c_copyGCISlave.m_senderData,
c_copyGCISlave.m_senderRef,
c_copyGCISlave.m_copyReason,
c_copyGCISlave.m_expectedNextWord);
FileRecordPtr file0Ptr;
file0Ptr.i = crestartInfoFile[0];
......@@ -12804,9 +12806,9 @@ void Dbdih::setLcpActiveStatusEnd()
nodePtr.i = getOwnNodeId();
ptrAss(nodePtr, nodeRecord);
ndbrequire(nodePtr.p->activeStatus == Sysfile::NS_Active);
ndbout_c("NR: setLcpActiveStatusEnd - m_participatingLQH");
g_eventLogger.info("NR: setLcpActiveStatusEnd - m_participatingLQH");
} else {
ndbout_c("NR: setLcpActiveStatusEnd - !m_participatingLQH");
g_eventLogger.info("NR: setLcpActiveStatusEnd - !m_participatingLQH");
}
}
......@@ -13637,8 +13639,8 @@ Dbdih::execDUMP_STATE_ORD(Signal* signal)
}
if(arg == DumpStateOrd::EnableUndoDelayDataWrite){
ndbout << "Dbdih:: delay write of datapages for table = "
<< dumpState->args[1]<< endl;
g_eventLogger.info("Dbdih:: delay write of datapages for table = %s",
dumpState->args[1]);
// Send this dump to ACC and TUP
EXECUTE_DIRECT(DBACC, GSN_DUMP_STATE_ORD, signal, 2);
EXECUTE_DIRECT(DBTUP, GSN_DUMP_STATE_ORD, signal, 2);
......@@ -13655,13 +13657,13 @@ Dbdih::execDUMP_STATE_ORD(Signal* signal)
}//if
if (signal->theData[0] == DumpStateOrd::DihMinTimeBetweenLCP) {
// Set time between LCP to min value
ndbout << "Set time between LCP to min value" << endl;
g_eventLogger.info("Set time between LCP to min value");
c_lcpState.clcpDelay = 0; // TimeBetweenLocalCheckpoints.min
return;
}
if (signal->theData[0] == DumpStateOrd::DihMaxTimeBetweenLCP) {
// Set time between LCP to max value
ndbout << "Set time between LCP to max value" << endl;
g_eventLogger.info("Set time between LCP to max value");
c_lcpState.clcpDelay = 31; // TimeBetweenLocalCheckpoints.max
return;
}
......@@ -13697,7 +13699,7 @@ Dbdih::execDUMP_STATE_ORD(Signal* signal)
{
cgcpDelay = signal->theData[1];
}
ndbout_c("Setting time between gcp : %d", cgcpDelay);
g_eventLogger.info("Setting time between gcp : %d", cgcpDelay);
}
if (arg == 7021 && signal->getLength() == 2)
......@@ -13820,7 +13822,7 @@ Dbdih::execPREP_DROP_TAB_REQ(Signal* signal){
while(index < count){
if(nodePtr.p->queuedChkpt[index].tableId == tabPtr.i){
jam();
// ndbout_c("Unqueuing %d", index);
// g_eventLogger.info("Unqueuing %d", index);
count--;
for(Uint32 i = index; i<count; i++){
......@@ -13860,7 +13862,7 @@ Dbdih::execPREP_DROP_TAB_REQ(Signal* signal){
if(checkLcpAllTablesDoneInLqh()){
jam();
ndbout_c("This is the last table");
g_eventLogger.info("This is the last table");
/**
* Then check if saving of tab info is done for all tables
......@@ -13869,7 +13871,7 @@ Dbdih::execPREP_DROP_TAB_REQ(Signal* signal){
checkLcpCompletedLab(signal);
if(a != c_lcpState.lcpStatus){
ndbout_c("And all tables are written to already written disk");
g_eventLogger.info("And all tables are written to already written disk");
}
}
break;
......
ndb/src/kernel/vm/WatchDog.cpp
View file @ 12542536
......@@ -22,7 +22,10 @@
#include <NdbOut.hpp>
#include <NdbSleep.h>
#include <ErrorHandlingMacros.hpp>
#include <EventLogger.hpp>
extern EventLogger g_eventLogger;
extern "C"
void*
runWatchDog(void* w){
......@@ -125,7 +128,7 @@ WatchDog::run(){
last_stuck_action = "Unknown place";
break;
}//switch
ndbout << "Ndb kernel is stuck in: " << last_stuck_action << endl;
g_eventLogger.warning("Ndb kernel is stuck in: %s", last_stuck_action);
if(alerts == 3){
shutdownSystem(last_stuck_action);
}
......
Markdown is supported
0% or
You are about to add 0 people to the discussion. Proceed with caution.
Finish editing this message first!
Please register or to comment
GitLab Nexedi Edition | About GitLab | About Nexedi | 沪ICP备2021021310号-2 | 沪ICP备2021021310号-7