diff --git a/include/libs/sync/sync.h b/include/libs/sync/sync.h index 10ece0b219312b133d237058be503da069421fb0..9d1385bff29865e75057acace93056ecf55eccf6 100644 --- a/include/libs/sync/sync.h +++ b/include/libs/sync/sync.h @@ -83,8 +83,10 @@ typedef struct SReConfigCbMeta { SyncTerm term; SyncTerm currentTerm; SSyncCfg oldCfg; + SSyncCfg newCfg; bool isDrop; uint64_t flag; + uint64_t seqNum; } SReConfigCbMeta; typedef struct SSnapshot { @@ -106,7 +108,7 @@ typedef struct SSyncFSM { void (*FpRollBackCb)(struct SSyncFSM* pFsm, const SRpcMsg* pMsg, SFsmCbMeta cbMeta); void (*FpRestoreFinishCb)(struct SSyncFSM* pFsm); - void (*FpReConfigCb)(struct SSyncFSM* pFsm, SSyncCfg newCfg, SReConfigCbMeta cbMeta); + void (*FpReConfigCb)(struct SSyncFSM* pFsm, const SRpcMsg* pMsg, SReConfigCbMeta cbMeta); int32_t (*FpGetSnapshot)(struct SSyncFSM* pFsm, SSnapshot* pSnapshot); @@ -184,7 +186,6 @@ int64_t syncOpen(const SSyncInfo* pSyncInfo); void syncStart(int64_t rid); void syncStop(int64_t rid); int32_t syncSetStandby(int64_t rid); -int32_t syncReconfig(int64_t rid, const SSyncCfg* pSyncCfg); ESyncState syncGetMyRole(int64_t rid); const char* syncGetMyRoleStr(int64_t rid); SyncTerm syncGetMyTerm(int64_t rid); @@ -194,8 +195,10 @@ int32_t syncPropose(int64_t rid, const SRpcMsg* pMsg, bool isWeak); bool syncEnvIsStart(); const char* syncStr(ESyncState state); bool syncIsRestoreFinish(int64_t rid); +int32_t syncGetSnapshotMeta(int64_t rid, struct SSnapshotMeta* sMeta); -int32_t syncGetSnapshotMeta(int64_t rid, struct SSnapshotMeta* sMeta); +int32_t syncReconfig(int64_t rid, const SSyncCfg* pNewCfg); +int32_t syncReconfigRaw(int64_t rid, const SSyncCfg* pNewCfg, SRpcMsg* pRpcMsg); // to be moved to static void syncStartNormal(int64_t rid); diff --git a/source/dnode/mnode/impl/src/mndSync.c b/source/dnode/mnode/impl/src/mndSync.c index a0daa72d9af1e1defedc564d338eef6baaef07c2..a0f722b3d25977b78d5a023626a97e12f4a4b226 100644 --- a/source/dnode/mnode/impl/src/mndSync.c +++ b/source/dnode/mnode/impl/src/mndSync.c @@ -96,10 +96,18 @@ void mndRestoreFinish(struct SSyncFSM *pFsm) { } } -void mndReConfig(struct SSyncFSM *pFsm, SSyncCfg newCfg, SReConfigCbMeta cbMeta) { +void mndReConfig(struct SSyncFSM *pFsm, const SRpcMsg *pMsg, SReConfigCbMeta cbMeta) { SMnode *pMnode = pFsm->data; SSyncMgmt *pMgmt = &pMnode->syncMgmt; +#if 0 +// send response + SRpcMsg rpcMsg = {.msgType = pMsg->msgType, .contLen = pMsg->contLen, .conn.applyIndex = cbMeta.index}; + rpcMsg.pCont = rpcMallocCont(rpcMsg.contLen); + memcpy(rpcMsg.pCont, pMsg->pCont, pMsg->contLen); + syncGetAndDelRespRpc(pMnode->syncMgmt.sync, cbMeta.seqNum, &rpcMsg.info); +#endif + pMgmt->errCode = cbMeta.code; mInfo("trans:-1, sync reconfig is proposed, saved:%d code:0x%x, index:%" PRId64 " term:%" PRId64, pMgmt->transId, cbMeta.code, cbMeta.index, cbMeta.term); diff --git a/source/dnode/vnode/src/vnd/vnodeSync.c b/source/dnode/vnode/src/vnd/vnodeSync.c index 087dcac7b716a5f66c9a67677855ec5e2509075f..b4021ec73d4679d266ab52b3ca53c46d17160d4a 100644 --- a/source/dnode/vnode/src/vnd/vnodeSync.c +++ b/source/dnode/vnode/src/vnd/vnodeSync.c @@ -180,10 +180,18 @@ static int32_t vnodeSyncGetSnapshot(SSyncFSM *pFsm, SSnapshot *pSnapshot) { return 0; } -static void vnodeSyncReconfig(struct SSyncFSM *pFsm, SSyncCfg newCfg, SReConfigCbMeta cbMeta) { +static void vnodeSyncReconfig(struct SSyncFSM *pFsm, const SRpcMsg *pMsg, SReConfigCbMeta cbMeta) { SVnode *pVnode = pFsm->data; vInfo("vgId:%d, sync reconfig is confirmed", TD_VID(pVnode)); +#if 0 +// send response + SRpcMsg rpcMsg = {.msgType = pMsg->msgType, .contLen = pMsg->contLen, .conn.applyIndex = cbMeta.index}; + rpcMsg.pCont = rpcMallocCont(rpcMsg.contLen); + memcpy(rpcMsg.pCont, pMsg->pCont, pMsg->contLen); + syncGetAndDelRespRpc(pVnode->sync, cbMeta.seqNum, &rpcMsg.info); +#endif + // todo rpc response here // build rpc msg // put into apply queue @@ -213,6 +221,7 @@ static void vnodeSyncCommitMsg(SSyncFSM *pFsm, const SRpcMsg *pMsg, SFsmCbMeta c memcpy(rpcMsg.pCont, pMsg->pCont, pMsg->contLen); syncGetAndDelRespRpc(pVnode->sync, cbMeta.seqNum, &rpcMsg.info); tmsgPutToQueue(&pVnode->msgCb, APPLY_QUEUE, &rpcMsg); + } else { char logBuf[256] = {0}; snprintf(logBuf, sizeof(logBuf), diff --git a/source/libs/sync/inc/syncInt.h b/source/libs/sync/inc/syncInt.h index 10218f69e6a7b1e7dedba0837340595bfad69a8d..83f0bd7dd81ee176e86aab64c8d0eb6ec56e253c 100644 --- a/source/libs/sync/inc/syncInt.h +++ b/source/libs/sync/inc/syncInt.h @@ -201,8 +201,8 @@ void syncNodeRelease(SSyncNode* pNode); // raft state change -------------- void syncNodeUpdateTerm(SSyncNode* pSyncNode, SyncTerm term); -void syncNodeBecomeFollower(SSyncNode* pSyncNode); -void syncNodeBecomeLeader(SSyncNode* pSyncNode); +void syncNodeBecomeFollower(SSyncNode* pSyncNode, const char* debugStr); +void syncNodeBecomeLeader(SSyncNode* pSyncNode, const char* debugStr); void syncNodeCandidate2Leader(SSyncNode* pSyncNode); void syncNodeFollower2Candidate(SSyncNode* pSyncNode); diff --git a/source/libs/sync/inc/syncRaftStore.h b/source/libs/sync/inc/syncRaftStore.h index 9f03ac3e558af787d2f401a0864213fc8a002ef6..e0cbcf074458f90e861a27ca4a0a1c026ed0fa03 100644 --- a/source/libs/sync/inc/syncRaftStore.h +++ b/source/libs/sync/inc/syncRaftStore.h @@ -49,8 +49,8 @@ void raftStoreClearVote(SRaftStore *pRaftStore); void raftStoreNextTerm(SRaftStore *pRaftStore); void raftStoreSetTerm(SRaftStore *pRaftStore, SyncTerm term); int32_t raftStoreFromJson(SRaftStore *pRaftStore, cJSON *pJson); -cJSON *raftStore2Json(SRaftStore *pRaftStore); -char *raftStore2Str(SRaftStore *pRaftStore); +cJSON * raftStore2Json(SRaftStore *pRaftStore); +char * raftStore2Str(SRaftStore *pRaftStore); // for debug ------------------- void raftStorePrint(SRaftStore *pObj); diff --git a/source/libs/sync/inc/syncSnapshot.h b/source/libs/sync/inc/syncSnapshot.h index b16e47b51eed7295c12bb592c05174b58245f785..9fbcdf138bac436e626a6f272127b2279b4c55fc 100644 --- a/source/libs/sync/inc/syncSnapshot.h +++ b/source/libs/sync/inc/syncSnapshot.h @@ -39,8 +39,8 @@ typedef struct SSyncSnapshotSender { bool start; int32_t seq; int32_t ack; - void *pReader; - void *pCurrentBlock; + void * pReader; + void * pCurrentBlock; int32_t blockLen; SSnapshot snapshot; int64_t sendingMS; @@ -58,28 +58,29 @@ void snapshotSenderStart(SSyncSnapshotSender *pSender); void snapshotSenderStop(SSyncSnapshotSender *pSender); int32_t snapshotSend(SSyncSnapshotSender *pSender); int32_t snapshotReSend(SSyncSnapshotSender *pSender); -cJSON *snapshotSender2Json(SSyncSnapshotSender *pSender); -char *snapshotSender2Str(SSyncSnapshotSender *pSender); +cJSON * snapshotSender2Json(SSyncSnapshotSender *pSender); +char * snapshotSender2Str(SSyncSnapshotSender *pSender); typedef struct SSyncSnapshotReceiver { bool start; int32_t ack; - void *pWriter; + void * pWriter; SyncTerm term; SyncTerm privateTerm; SSyncNode *pSyncNode; - int32_t replicaIndex; + SRaftId fromId; + } SSyncSnapshotReceiver; -SSyncSnapshotReceiver *snapshotReceiverCreate(SSyncNode *pSyncNode, int32_t replicaIndex); +SSyncSnapshotReceiver *snapshotReceiverCreate(SSyncNode *pSyncNode, SRaftId fromId); void snapshotReceiverDestroy(SSyncSnapshotReceiver *pReceiver); -void snapshotReceiverStart(SSyncSnapshotReceiver *pReceiver, SyncTerm privateTerm); +void snapshotReceiverStart(SSyncSnapshotReceiver *pReceiver, SyncTerm privateTerm, SRaftId fromId); bool snapshotReceiverIsStart(SSyncSnapshotReceiver *pReceiver); void snapshotReceiverStop(SSyncSnapshotReceiver *pReceiver, bool apply); -cJSON *snapshotReceiver2Json(SSyncSnapshotReceiver *pReceiver); -char *snapshotReceiver2Str(SSyncSnapshotReceiver *pReceiver); +cJSON * snapshotReceiver2Json(SSyncSnapshotReceiver *pReceiver); +char * snapshotReceiver2Str(SSyncSnapshotReceiver *pReceiver); int32_t syncNodeOnSnapshotSendCb(SSyncNode *ths, SyncSnapshotSend *pMsg); int32_t syncNodeOnSnapshotRspCb(SSyncNode *ths, SyncSnapshotRsp *pMsg); diff --git a/source/libs/sync/src/syncAppendEntries.c b/source/libs/sync/src/syncAppendEntries.c index 3c558b60c8b21f79f06369a097e596c3d182541c..01c95d824114bc718aeda27096bc4584b9f01ccb 100644 --- a/source/libs/sync/src/syncAppendEntries.c +++ b/source/libs/sync/src/syncAppendEntries.c @@ -150,7 +150,7 @@ int32_t syncNodeOnAppendEntriesCb(SSyncNode* ths, SyncAppendEntries* pMsg) { "ths->state:%d, logOK:%d", pMsg->term, ths->pRaftStore->currentTerm, ths->state, logOK); - syncNodeBecomeFollower(ths); + syncNodeBecomeFollower(ths, "from candidate by append entries"); // ret or reply? return ret; @@ -380,17 +380,19 @@ int32_t syncNodeOnAppendEntriesCb(SSyncNode* ths, SyncAppendEntries* pMsg) { // change isStandBy to normal if (!isDrop) { if (ths->state == TAOS_SYNC_STATE_LEADER) { - syncNodeBecomeLeader(ths); + syncNodeBecomeLeader(ths, "config change"); } else { - syncNodeBecomeFollower(ths); + syncNodeBecomeFollower(ths, "config change"); } } - char* sOld = syncCfg2Str(&oldSyncCfg); - char* sNew = syncCfg2Str(&newSyncCfg); - sInfo("==config change== 0x11 old:%s new:%s isDrop:%d \n", sOld, sNew, isDrop); - taosMemoryFree(sOld); - taosMemoryFree(sNew); + if (gRaftDetailLog) { + char* sOld = syncCfg2Str(&oldSyncCfg); + char* sNew = syncCfg2Str(&newSyncCfg); + sInfo("==config change== 0x11 old:%s new:%s isDrop:%d \n", sOld, sNew, isDrop); + taosMemoryFree(sOld); + taosMemoryFree(sNew); + } } // always call FpReConfigCb @@ -399,10 +401,12 @@ int32_t syncNodeOnAppendEntriesCb(SSyncNode* ths, SyncAppendEntries* pMsg) { cbMeta.currentTerm = ths->pRaftStore->currentTerm; cbMeta.index = pEntry->index; cbMeta.term = pEntry->term; + cbMeta.newCfg = newSyncCfg; cbMeta.oldCfg = oldSyncCfg; + cbMeta.seqNum = pEntry->seqNum; cbMeta.flag = 0x11; cbMeta.isDrop = isDrop; - ths->pFsm->FpReConfigCb(ths->pFsm, newSyncCfg, cbMeta); + ths->pFsm->FpReConfigCb(ths->pFsm, &rpcMsg, cbMeta); } } @@ -469,7 +473,7 @@ static int32_t syncNodeMakeLogSame(SSyncNode* ths, SyncAppendEntries* pMsg) { // delete confict entries code = ths->pLogStore->syncLogTruncate(ths->pLogStore, delBegin); ASSERT(code == 0); - sInfo("sync event log truncate, from %ld to %ld", delBegin, delEnd); + sInfo("sync event vgId:%d log truncate, from %ld to %ld", ths->vgId, delBegin, delEnd); logStoreSimpleLog2("after syncNodeMakeLogSame", ths->pLogStore); return code; @@ -571,7 +575,7 @@ int32_t syncNodeOnAppendEntriesSnapshotCb(SSyncNode* ths, SyncAppendEntries* pMs if (condition) { sTrace("recv SyncAppendEntries, candidate to follower"); - syncNodeBecomeFollower(ths); + syncNodeBecomeFollower(ths, "from candidate by append entries"); // do not reply? return ret; } @@ -742,6 +746,18 @@ int32_t syncNodeOnAppendEntriesSnapshotCb(SSyncNode* ths, SyncAppendEntries* pMs if (pMsg->commitIndex > ths->commitIndex) { // has commit entry in local if (pMsg->commitIndex <= ths->pLogStore->syncLogLastIndex(ths->pLogStore)) { + // advance commit index to sanpshot first + SSnapshot snapshot; + ths->pFsm->FpGetSnapshot(ths->pFsm, &snapshot); + if (snapshot.lastApplyIndex >= 0 && snapshot.lastApplyIndex > ths->commitIndex) { + SyncIndex commitBegin = ths->commitIndex; + SyncIndex commitEnd = snapshot.lastApplyIndex; + ths->commitIndex = snapshot.lastApplyIndex; + + sInfo("sync event vgId:%d commit by snapshot from index:%ld to index:%ld, %s", ths->vgId, commitBegin, + commitEnd, syncUtilState2String(ths->state)); + } + SyncIndex beginIndex = ths->commitIndex + 1; SyncIndex endIndex = pMsg->commitIndex; diff --git a/source/libs/sync/src/syncAppendEntriesReply.c b/source/libs/sync/src/syncAppendEntriesReply.c index 5a543e1605d8613f758e315152341fe985ab579c..7fc35afbb18dfd4b25fc05ed2e7fd98eeaf9caf4 100644 --- a/source/libs/sync/src/syncAppendEntriesReply.c +++ b/source/libs/sync/src/syncAppendEntriesReply.c @@ -121,7 +121,7 @@ int32_t syncNodeOnAppendEntriesReplySnapshotCb(SSyncNode* ths, SyncAppendEntries syncIndexMgrLog2("recv SyncAppendEntriesReply, before pNextIndex:", ths->pNextIndex); syncIndexMgrLog2("recv SyncAppendEntriesReply, before pMatchIndex:", ths->pMatchIndex); - { + if (gRaftDetailLog) { SSnapshot snapshot; ths->pFsm->FpGetSnapshot(ths->pFsm, &snapshot); sTrace("recv SyncAppendEntriesReply, before snapshot.lastApplyIndex:%ld, snapshot.lastApplyTerm:%lu", @@ -147,7 +147,10 @@ int32_t syncNodeOnAppendEntriesReplySnapshotCb(SSyncNode* ths, SyncAppendEntries if (pMsg->success) { // nextIndex' = [nextIndex EXCEPT ![i][j] = m.mmatchIndex + 1] syncIndexMgrSetIndex(ths->pNextIndex, &(pMsg->srcId), pMsg->matchIndex + 1); - sTrace("update next match, index:%ld, success:%d", pMsg->matchIndex + 1, pMsg->success); + + if (gRaftDetailLog) { + sTrace("update next match, index:%ld, success:%d", pMsg->matchIndex + 1, pMsg->success); + } // matchIndex' = [matchIndex EXCEPT ![i][j] = m.mmatchIndex] syncIndexMgrSetIndex(ths->pMatchIndex, &(pMsg->srcId), pMsg->matchIndex); @@ -159,7 +162,9 @@ int32_t syncNodeOnAppendEntriesReplySnapshotCb(SSyncNode* ths, SyncAppendEntries } else { SyncIndex nextIndex = syncIndexMgrGetIndex(ths->pNextIndex, &(pMsg->srcId)); - sTrace("update next not match, begin, index:%ld, success:%d", nextIndex, pMsg->success); + if (gRaftDetailLog) { + sTrace("update next index not match, begin, index:%ld, success:%d", nextIndex, pMsg->success); + } // notice! int64, uint64 if (nextIndex > SYNC_INDEX_BEGIN) { @@ -178,9 +183,23 @@ int32_t syncNodeOnAppendEntriesReplySnapshotCb(SSyncNode* ths, SyncAppendEntries pMsg->privateTerm < pSender->privateTerm) { snapshotSenderStart(pSender); - char* s = snapshotSender2Str(pSender); - sInfo("sync event snapshot send start sender first time, sender:%s", s); - taosMemoryFree(s); + char host[128]; + uint16_t port; + syncUtilU642Addr(pSender->pSyncNode->replicasId[pSender->replicaIndex].addr, host, sizeof(host), &port); + + if (gRaftDetailLog) { + char* s = snapshotSender2Str(pSender); + sInfo( + "sync event vgId:%d snapshot send to %s:%d start sender first time, lastApplyIndex:%ld lastApplyTerm:%lu " + "sender:%s", + ths->vgId, host, port, pSender->snapshot.lastApplyIndex, pSender->snapshot.lastApplyTerm, s); + taosMemoryFree(s); + } else { + sInfo( + "sync event vgId:%d snapshot send to %s:%d start sender first time, lastApplyIndex:%ld " + "lastApplyTerm:%lu", + ths->vgId, host, port, pSender->snapshot.lastApplyIndex, pSender->snapshot.lastApplyTerm); + } } SyncIndex sentryIndex = pSender->snapshot.lastApplyIndex + 1; @@ -195,12 +214,14 @@ int32_t syncNodeOnAppendEntriesReplySnapshotCb(SSyncNode* ths, SyncAppendEntries } syncIndexMgrSetIndex(ths->pNextIndex, &(pMsg->srcId), nextIndex); - sTrace("update next not match, end, index:%ld, success:%d", nextIndex, pMsg->success); + if (gRaftDetailLog) { + sTrace("update next index not match, end, index:%ld, success:%d", nextIndex, pMsg->success); + } } syncIndexMgrLog2("recv SyncAppendEntriesReply, after pNextIndex:", ths->pNextIndex); syncIndexMgrLog2("recv SyncAppendEntriesReply, after pMatchIndex:", ths->pMatchIndex); - { + if (gRaftDetailLog) { SSnapshot snapshot; ths->pFsm->FpGetSnapshot(ths->pFsm, &snapshot); sTrace("recv SyncAppendEntriesReply, after snapshot.lastApplyIndex:%ld, snapshot.lastApplyTerm:%lu", diff --git a/source/libs/sync/src/syncCommit.c b/source/libs/sync/src/syncCommit.c index c092b31adf9a7acb2bfaed72371f8f56968f2d13..8236301f8e33056f7d835ea46d9a362b22365d9e 100644 --- a/source/libs/sync/src/syncCommit.c +++ b/source/libs/sync/src/syncCommit.c @@ -48,13 +48,28 @@ void syncMaybeAdvanceCommitIndex(SSyncNode* pSyncNode) { syncIndexMgrLog2("==syncNodeMaybeAdvanceCommitIndex== pNextIndex", pSyncNode->pNextIndex); syncIndexMgrLog2("==syncNodeMaybeAdvanceCommitIndex== pMatchIndex", pSyncNode->pMatchIndex); + // advance commit index to sanpshot first + SSnapshot snapshot; + pSyncNode->pFsm->FpGetSnapshot(pSyncNode->pFsm, &snapshot); + if (snapshot.lastApplyIndex > 0 && snapshot.lastApplyIndex > pSyncNode->commitIndex) { + SyncIndex commitBegin = pSyncNode->commitIndex; + SyncIndex commitEnd = snapshot.lastApplyIndex; + pSyncNode->commitIndex = snapshot.lastApplyIndex; + + sInfo("sync event vgId:%d commit by snapshot from index:%ld to index:%ld, %s", pSyncNode->vgId, + pSyncNode->commitIndex, snapshot.lastApplyIndex, syncUtilState2String(pSyncNode->state)); + } + // update commit index SyncIndex newCommitIndex = pSyncNode->commitIndex; - for (SyncIndex index = pSyncNode->pLogStore->getLastIndex(pSyncNode->pLogStore); index > pSyncNode->commitIndex; - --index) { + for (SyncIndex index = syncNodeGetLastIndex(pSyncNode); index > pSyncNode->commitIndex; --index) { bool agree = syncAgree(pSyncNode, index); - sTrace("syncMaybeAdvanceCommitIndex syncAgree:%d, index:%ld, pSyncNode->commitIndex:%ld", agree, index, - pSyncNode->commitIndex); + + if (gRaftDetailLog) { + sTrace("syncMaybeAdvanceCommitIndex syncAgree:%d, index:%ld, pSyncNode->commitIndex:%ld", agree, index, + pSyncNode->commitIndex); + } + if (agree) { // term SSyncRaftEntry* pEntry = pSyncNode->pLogStore->getEntry(pSyncNode->pLogStore, index); @@ -64,16 +79,21 @@ void syncMaybeAdvanceCommitIndex(SSyncNode* pSyncNode) { if (pEntry->term == pSyncNode->pRaftStore->currentTerm) { // update commit index newCommitIndex = index; - sTrace("syncMaybeAdvanceCommitIndex maybe to update, newCommitIndex:%ld commit, pSyncNode->commitIndex:%ld", - newCommitIndex, pSyncNode->commitIndex); + + if (gRaftDetailLog) { + sTrace("syncMaybeAdvanceCommitIndex maybe to update, newCommitIndex:%ld commit, pSyncNode->commitIndex:%ld", + newCommitIndex, pSyncNode->commitIndex); + } syncEntryDestory(pEntry); break; } else { - sTrace( - "syncMaybeAdvanceCommitIndex can not commit due to term not equal, pEntry->term:%lu, " - "pSyncNode->pRaftStore->currentTerm:%lu", - pEntry->term, pSyncNode->pRaftStore->currentTerm); + if (gRaftDetailLog) { + sTrace( + "syncMaybeAdvanceCommitIndex can not commit due to term not equal, pEntry->term:%lu, " + "pSyncNode->pRaftStore->currentTerm:%lu", + pEntry->term, pSyncNode->pRaftStore->currentTerm); + } } syncEntryDestory(pEntry); @@ -84,7 +104,9 @@ void syncMaybeAdvanceCommitIndex(SSyncNode* pSyncNode) { SyncIndex beginIndex = pSyncNode->commitIndex + 1; SyncIndex endIndex = newCommitIndex; - sTrace("syncMaybeAdvanceCommitIndex sync commit %ld", newCommitIndex); + if (gRaftDetailLog) { + sTrace("syncMaybeAdvanceCommitIndex sync commit %ld", newCommitIndex); + } // update commit index pSyncNode->commitIndex = newCommitIndex; diff --git a/source/libs/sync/src/syncEnv.c b/source/libs/sync/src/syncEnv.c index 945d59646b08ae303c5ffa36f6fb4d3a1fb85452..e67439f8feae8601e75e0c8df2dcc82aced32a86 100644 --- a/source/libs/sync/src/syncEnv.c +++ b/source/libs/sync/src/syncEnv.c @@ -40,7 +40,7 @@ int32_t syncEnvStart() { // gSyncEnv = doSyncEnvStart(gSyncEnv); gSyncEnv = doSyncEnvStart(); assert(gSyncEnv != NULL); - sTrace("syncEnvStart ok!"); + sTrace("sync env start ok"); return ret; } diff --git a/source/libs/sync/src/syncIndexMgr.c b/source/libs/sync/src/syncIndexMgr.c index ecc1c8f1e2bb4b36afeed07d67829c98dd632a69..18cb55b417411b46e9482409b40fc5dc477513f7 100644 --- a/source/libs/sync/src/syncIndexMgr.c +++ b/source/libs/sync/src/syncIndexMgr.c @@ -119,7 +119,7 @@ cJSON *syncIndexMgr2Json(SSyncIndexMgr *pSyncIndexMgr) { char *syncIndexMgr2Str(SSyncIndexMgr *pSyncIndexMgr) { cJSON *pJson = syncIndexMgr2Json(pSyncIndexMgr); - char *serialized = cJSON_Print(pJson); + char * serialized = cJSON_Print(pJson); cJSON_Delete(pJson); return serialized; } diff --git a/source/libs/sync/src/syncMain.c b/source/libs/sync/src/syncMain.c index 9516df64dacabc5b31d9b5c84664ddf37eb7ae20..26dbf6c47a37a23d70b08ac98de06b60cffd7aa2 100644 --- a/source/libs/sync/src/syncMain.c +++ b/source/libs/sync/src/syncMain.c @@ -87,7 +87,9 @@ int64_t syncOpen(const SSyncInfo* pSyncInfo) { SSyncNode* pSyncNode = syncNodeOpen(pSyncInfo); assert(pSyncNode != NULL); - syncNodeLog2("syncNodeOpen open success", pSyncNode); + if (gRaftDetailLog) { + syncNodeLog2("syncNodeOpen open success", pSyncNode); + } pSyncNode->rid = taosAddRef(tsNodeRefId, pSyncNode); if (pSyncNode->rid < 0) { @@ -173,20 +175,37 @@ int32_t syncSetStandby(int64_t rid) { int32_t syncReconfig(int64_t rid, const SSyncCfg* pSyncCfg) { int32_t ret = 0; - char* configChange = syncCfg2Str((SSyncCfg*)pSyncCfg); - sInfo("==syncReconfig== newconfig:%s", configChange); + char* newconfig = syncCfg2Str((SSyncCfg*)pSyncCfg); + + if (gRaftDetailLog) { + sInfo("==syncReconfig== newconfig:%s", newconfig); + } SRpcMsg rpcMsg = {0}; rpcMsg.msgType = TDMT_SYNC_CONFIG_CHANGE; rpcMsg.info.noResp = 1; - rpcMsg.contLen = strlen(configChange) + 1; + rpcMsg.contLen = strlen(newconfig) + 1; rpcMsg.pCont = rpcMallocCont(rpcMsg.contLen); - snprintf(rpcMsg.pCont, rpcMsg.contLen, "%s", configChange); - taosMemoryFree(configChange); + snprintf(rpcMsg.pCont, rpcMsg.contLen, "%s", newconfig); + taosMemoryFree(newconfig); ret = syncPropose(rid, &rpcMsg, false); return ret; } +int32_t syncReconfigRaw(int64_t rid, const SSyncCfg* pNewCfg, SRpcMsg* pRpcMsg) { + int32_t ret = 0; + char* newconfig = syncCfg2Str((SSyncCfg*)pNewCfg); + + pRpcMsg->msgType = TDMT_SYNC_CONFIG_CHANGE; + pRpcMsg->info.noResp = 1; + pRpcMsg->contLen = strlen(newconfig) + 1; + pRpcMsg->pCont = rpcMallocCont(pRpcMsg->contLen); + snprintf(pRpcMsg->pCont, pRpcMsg->contLen, "%s", newconfig); + taosMemoryFree(newconfig); + + return ret; +} + int32_t syncForwardToPeer(int64_t rid, const SRpcMsg* pMsg, bool isWeak) { int32_t ret = syncPropose(rid, pMsg, isWeak); return ret; @@ -374,13 +393,14 @@ void setHeartbeatTimerMS(int64_t rid, int32_t hbTimerMS) { } int32_t syncPropose(int64_t rid, const SRpcMsg* pMsg, bool isWeak) { - sTrace("syncPropose msgType:%d ", pMsg->msgType); + int32_t ret = TAOS_SYNC_PROPOSE_SUCCESS; - int32_t ret = TAOS_SYNC_PROPOSE_SUCCESS; SSyncNode* pSyncNode = taosAcquireRef(tsNodeRefId, rid); - if (pSyncNode == NULL) return TAOS_SYNC_PROPOSE_OTHER_ERROR; - + if (pSyncNode == NULL) { + return TAOS_SYNC_PROPOSE_OTHER_ERROR; + } assert(rid == pSyncNode->rid); + sTrace("sync event vgId:%d propose msgType:%s", pSyncNode->vgId, TMSG_INFO(pMsg->msgType)); if (pSyncNode->state == TAOS_SYNC_STATE_LEADER) { SRespStub stub; @@ -411,6 +431,8 @@ int32_t syncPropose(int64_t rid, const SRpcMsg* pMsg, bool isWeak) { SSyncNode* syncNodeOpen(const SSyncInfo* pOldSyncInfo) { SSyncInfo* pSyncInfo = (SSyncInfo*)pOldSyncInfo; + sInfo("sync event vgId:%d sync open", pSyncInfo->vgId); + SSyncNode* pSyncNode = (SSyncNode*)taosMemoryMalloc(sizeof(SSyncNode)); assert(pSyncNode != NULL); memset(pSyncNode, 0, sizeof(SSyncNode)); @@ -439,9 +461,11 @@ SSyncNode* syncNodeOpen(const SSyncInfo* pOldSyncInfo) { assert(pSyncNode->pRaftCfg != NULL); pSyncInfo->syncCfg = pSyncNode->pRaftCfg->cfg; - char* seralized = raftCfg2Str(pSyncNode->pRaftCfg); - sInfo("syncNodeOpen update config :%s", seralized); - taosMemoryFree(seralized); + if (gRaftDetailLog) { + char* seralized = raftCfg2Str(pSyncNode->pRaftCfg); + sInfo("syncNodeOpen update config :%s", seralized); + taosMemoryFree(seralized); + } raftCfgClose(pSyncNode->pRaftCfg); } @@ -612,7 +636,7 @@ SSyncNode* syncNodeOpen(const SSyncInfo* pOldSyncInfo) { } // snapshot receivers - pSyncNode->pNewNodeReceiver = snapshotReceiverCreate(pSyncNode, 100); + pSyncNode->pNewNodeReceiver = snapshotReceiverCreate(pSyncNode, EMPTY_RAFT_ID); // start in syncNodeStart // start raft @@ -628,9 +652,7 @@ void syncNodeStart(SSyncNode* pSyncNode) { // start raft if (pSyncNode->replicaNum == 1) { raftStoreNextTerm(pSyncNode->pRaftStore); - syncNodeBecomeLeader(pSyncNode); - - syncNodeLog2("==state change become leader immediately==", pSyncNode); + syncNodeBecomeLeader(pSyncNode, "one replica start"); // Raft 3.6.2 Committing entries from previous terms @@ -638,41 +660,22 @@ void syncNodeStart(SSyncNode* pSyncNode) { syncNodeAppendNoop(pSyncNode); syncMaybeAdvanceCommitIndex(pSyncNode); // maybe only one replica - /* - sInfo("==syncNodeStart== RestoreFinish begin 1 replica tsem_wait %p", pSyncNode); - tsem_wait(&pSyncNode->restoreSem); - sInfo("==syncNodeStart== RestoreFinish end 1 replica tsem_wait %p", pSyncNode); - */ - - /* - while (pSyncNode->restoreFinish != true) { - taosMsleep(10); + if (gRaftDetailLog) { + syncNodeLog2("==state change become leader immediately==", pSyncNode); } - */ - sInfo("==syncNodeStart== restoreFinish ok 1 replica %p vgId:%d", pSyncNode, pSyncNode->vgId); return; } - syncNodeBecomeFollower(pSyncNode); + syncNodeBecomeFollower(pSyncNode, "first start"); - // for test - int32_t ret = 0; + // int32_t ret = 0; // ret = syncNodeStartPingTimer(pSyncNode); - assert(ret == 0); - - /* - sInfo("==syncNodeStart== RestoreFinish begin multi replica tsem_wait %p", pSyncNode); - tsem_wait(&pSyncNode->restoreSem); - sInfo("==syncNodeStart== RestoreFinish end multi replica tsem_wait %p", pSyncNode); - */ + // assert(ret == 0); - /* - while (pSyncNode->restoreFinish != true) { - taosMsleep(10); + if (gRaftDetailLog) { + syncNodeLog2("==state change become leader immediately==", pSyncNode); } - */ - sInfo("==syncNodeStart== restoreFinish ok multi replica %p vgId:%d", pSyncNode, pSyncNode->vgId); } void syncNodeStartStandBy(SSyncNode* pSyncNode) { @@ -687,6 +690,8 @@ void syncNodeStartStandBy(SSyncNode* pSyncNode) { } void syncNodeClose(SSyncNode* pSyncNode) { + sInfo("sync event vgId:%d sync close", pSyncNode->vgId); + int32_t ret; assert(pSyncNode != NULL); @@ -1131,7 +1136,10 @@ void syncNodeUpdateConfig(SSyncNode* pSyncNode, SSyncCfg* newConfig, bool* isDro } raftCfgPersist(pSyncNode->pRaftCfg); - syncNodeLog2("==syncNodeUpdateConfig==", pSyncNode); + + if (gRaftDetailLog) { + syncNodeLog2("==syncNodeUpdateConfig==", pSyncNode); + } } SSyncNode* syncNodeAcquire(int64_t rid) { @@ -1149,12 +1157,14 @@ void syncNodeRelease(SSyncNode* pNode) { taosReleaseRef(tsNodeRefId, pNode->rid) void syncNodeUpdateTerm(SSyncNode* pSyncNode, SyncTerm term) { if (term > pSyncNode->pRaftStore->currentTerm) { raftStoreSetTerm(pSyncNode->pRaftStore, term); - syncNodeBecomeFollower(pSyncNode); + syncNodeBecomeFollower(pSyncNode, "update term"); raftStoreClearVote(pSyncNode->pRaftStore); } } -void syncNodeBecomeFollower(SSyncNode* pSyncNode) { +void syncNodeBecomeFollower(SSyncNode* pSyncNode, const char* debugStr) { + sInfo("sync event vgId:%d become follower, %s", pSyncNode->vgId, debugStr); + // maybe clear leader cache if (pSyncNode->state == TAOS_SYNC_STATE_LEADER) { pSyncNode->leaderCache = EMPTY_RAFT_ID; @@ -1186,7 +1196,9 @@ void syncNodeBecomeFollower(SSyncNode* pSyncNode) { // evoterLog |-> voterLog[i]]} // /\ UNCHANGED <> // -void syncNodeBecomeLeader(SSyncNode* pSyncNode) { +void syncNodeBecomeLeader(SSyncNode* pSyncNode, const char* debugStr) { + sInfo("sync event vgId:%d become leader, %s", pSyncNode->vgId, debugStr); + // state change pSyncNode->state = TAOS_SYNC_STATE_LEADER; @@ -1237,7 +1249,7 @@ void syncNodeBecomeLeader(SSyncNode* pSyncNode) { void syncNodeCandidate2Leader(SSyncNode* pSyncNode) { assert(pSyncNode->state == TAOS_SYNC_STATE_CANDIDATE); assert(voteGrantedMajority(pSyncNode->pVotesGranted)); - syncNodeBecomeLeader(pSyncNode); + syncNodeBecomeLeader(pSyncNode, "candidate to leader"); syncNodeLog2("==state change syncNodeCandidate2Leader==", pSyncNode); @@ -1260,14 +1272,14 @@ void syncNodeFollower2Candidate(SSyncNode* pSyncNode) { void syncNodeLeader2Follower(SSyncNode* pSyncNode) { assert(pSyncNode->state == TAOS_SYNC_STATE_LEADER); - syncNodeBecomeFollower(pSyncNode); + syncNodeBecomeFollower(pSyncNode, "leader to follower"); syncNodeLog2("==state change syncNodeLeader2Follower==", pSyncNode); } void syncNodeCandidate2Follower(SSyncNode* pSyncNode) { assert(pSyncNode->state == TAOS_SYNC_STATE_CANDIDATE); - syncNodeBecomeFollower(pSyncNode); + syncNodeBecomeFollower(pSyncNode, "candidate to follower"); syncNodeLog2("==state change syncNodeCandidate2Follower==", pSyncNode); } @@ -1467,9 +1479,11 @@ void syncNodeLog(SSyncNode* pObj) { } void syncNodeLog2(char* s, SSyncNode* pObj) { - char* serialized = syncNode2Str(pObj); - sTraceLong("syncNodeLog2 | len:%lu | %s | %s", strlen(serialized), s, serialized); - taosMemoryFree(serialized); + if (gRaftDetailLog) { + char* serialized = syncNode2Str(pObj); + sTraceLong("syncNodeLog2 | len:%lu | %s | %s", strlen(serialized), s, serialized); + taosMemoryFree(serialized); + } } // ------ local funciton --------- @@ -1724,17 +1738,19 @@ const char* syncStr(ESyncState state) { int32_t syncNodeCommit(SSyncNode* ths, SyncIndex beginIndex, SyncIndex endIndex, uint64_t flag) { int32_t code = 0; ESyncState state = flag; - sInfo("sync event commit from index:%" PRId64 " to index:%" PRId64 ", %s", beginIndex, endIndex, - syncUtilState2String(state)); + sInfo("sync event vgId:%d commit by wal from index:%" PRId64 " to index:%" PRId64 ", %s", ths->vgId, beginIndex, + endIndex, syncUtilState2String(state)); - // maybe execute by leader, skip snapshot - SSnapshot snapshot = {.data = NULL, .lastApplyIndex = -1, .lastApplyTerm = 0}; - if (ths->pFsm->FpGetSnapshot != NULL) { - ths->pFsm->FpGetSnapshot(ths->pFsm, &snapshot); - } - if (beginIndex <= snapshot.lastApplyIndex) { - beginIndex = snapshot.lastApplyIndex + 1; - } + /* + // maybe execute by leader, skip snapshot + SSnapshot snapshot = {.data = NULL, .lastApplyIndex = -1, .lastApplyTerm = 0}; + if (ths->pFsm->FpGetSnapshot != NULL) { + ths->pFsm->FpGetSnapshot(ths->pFsm, &snapshot); + } + if (beginIndex <= snapshot.lastApplyIndex) { + beginIndex = snapshot.lastApplyIndex + 1; + } + */ // execute fsm if (ths->pFsm != NULL) { @@ -1791,17 +1807,19 @@ int32_t syncNodeCommit(SSyncNode* ths, SyncIndex beginIndex, SyncIndex endIndex, // change isStandBy to normal if (!isDrop) { if (ths->state == TAOS_SYNC_STATE_LEADER) { - syncNodeBecomeLeader(ths); + syncNodeBecomeLeader(ths, "config change"); } else { - syncNodeBecomeFollower(ths); + syncNodeBecomeFollower(ths, "config change"); } } - char* sOld = syncCfg2Str(&oldSyncCfg); - char* sNew = syncCfg2Str(&newSyncCfg); - sInfo("==config change== 0x11 old:%s new:%s isDrop:%d \n", sOld, sNew, isDrop); - taosMemoryFree(sOld); - taosMemoryFree(sNew); + if (gRaftDetailLog) { + char* sOld = syncCfg2Str(&oldSyncCfg); + char* sNew = syncCfg2Str(&newSyncCfg); + sInfo("==config change== 0x11 old:%s new:%s isDrop:%d \n", sOld, sNew, isDrop); + taosMemoryFree(sOld); + taosMemoryFree(sNew); + } } // always call FpReConfigCb @@ -1810,10 +1828,12 @@ int32_t syncNodeCommit(SSyncNode* ths, SyncIndex beginIndex, SyncIndex endIndex, cbMeta.currentTerm = ths->pRaftStore->currentTerm; cbMeta.index = pEntry->index; cbMeta.term = pEntry->term; + cbMeta.newCfg = newSyncCfg; cbMeta.oldCfg = oldSyncCfg; + cbMeta.seqNum = pEntry->seqNum; cbMeta.flag = 0x11; cbMeta.isDrop = isDrop; - ths->pFsm->FpReConfigCb(ths->pFsm, newSyncCfg, cbMeta); + ths->pFsm->FpReConfigCb(ths->pFsm, &rpcMsg, cbMeta); } } @@ -1824,7 +1844,7 @@ int32_t syncNodeCommit(SSyncNode* ths, SyncIndex beginIndex, SyncIndex endIndex, ths->pFsm->FpRestoreFinishCb(ths->pFsm); } ths->restoreFinish = true; - sInfo("restore finish %p vgId:%d", ths, ths->vgId); + sInfo("sync event vgId:%d restore finish", ths->vgId); } } diff --git a/source/libs/sync/src/syncRaftLog.c b/source/libs/sync/src/syncRaftLog.c index 49509ae979de536c2afd65a84acafacc3d8b9d6a..c53e5916ae0db5ac2264cdf51aab193d343dd718 100644 --- a/source/libs/sync/src/syncRaftLog.c +++ b/source/libs/sync/src/syncRaftLog.c @@ -14,6 +14,7 @@ */ #include "syncRaftLog.h" +#include "syncRaftCfg.h" #include "wal.h" // refactor, log[0 .. n] ==> log[m .. n] @@ -161,7 +162,9 @@ static int32_t raftLogAppendEntry(struct SSyncLogStore* pLogStore, SSyncRaftEntr walFsync(pWal, true); - sTrace("sync event write index:%" PRId64, pEntry->index); + sTrace("sync event vgId:%d write index:%ld, %s, isStandBy:%d, msgType:%s, originalRpcType:%s", pData->pSyncNode->vgId, + pEntry->index, syncUtilState2String(pData->pSyncNode->state), pData->pSyncNode->pRaftCfg->isStandBy, + TMSG_INFO(pEntry->msgType), TMSG_INFO(pEntry->originalRpcType)); return code; } diff --git a/source/libs/sync/src/syncReplication.c b/source/libs/sync/src/syncReplication.c index ff39b0b13dfb5145eb53753ab2b5750d33bfbd82..08564f8293695c1eb2155191c3ae1b28396962e6 100644 --- a/source/libs/sync/src/syncReplication.c +++ b/source/libs/sync/src/syncReplication.c @@ -122,7 +122,7 @@ int32_t syncNodeAppendEntriesPeersSnapshot(SSyncNode* pSyncNode) { syncIndexMgrLog2("begin append entries peers pNextIndex:", pSyncNode->pNextIndex); syncIndexMgrLog2("begin append entries peers pMatchIndex:", pSyncNode->pMatchIndex); logStoreSimpleLog2("begin append entries peers LogStore:", pSyncNode->pLogStore); - { + if (gRaftDetailLog) { SSnapshot snapshot; pSyncNode->pFsm->FpGetSnapshot(pSyncNode->pFsm, &snapshot); sTrace("begin append entries peers, snapshot.lastApplyIndex:%ld, snapshot.lastApplyTerm:%lu", @@ -201,7 +201,6 @@ int32_t syncNodeReplicate(SSyncNode* pSyncNode) { } int32_t syncNodeAppendEntries(SSyncNode* pSyncNode, const SRaftId* destRaftId, const SyncAppendEntries* pMsg) { - sTrace("syncNodeAppendEntries pSyncNode:%p ", pSyncNode); int32_t ret = 0; SRpcMsg rpcMsg; diff --git a/source/libs/sync/src/syncSnapshot.c b/source/libs/sync/src/syncSnapshot.c index a68312d07f6a6d2512d1971b3cb0b0c5c4f63d95..a23fe2c38a84b8c83156868b4c198372d128aa08 100644 --- a/source/libs/sync/src/syncSnapshot.c +++ b/source/libs/sync/src/syncSnapshot.c @@ -20,7 +20,7 @@ #include "syncUtil.h" #include "wal.h" -static void snapshotReceiverDoStart(SSyncSnapshotReceiver *pReceiver, SyncTerm privateTerm); +static void snapshotReceiverDoStart(SSyncSnapshotReceiver *pReceiver, SyncTerm privateTerm, SRaftId fromId); //---------------------------------- SSyncSnapshotSender *snapshotSenderCreate(SSyncNode *pSyncNode, int32_t replicaIndex) { @@ -105,13 +105,23 @@ void snapshotSenderStart(SSyncSnapshotSender *pSender) { syncSnapshotSend2RpcMsg(pMsg, &rpcMsg); syncNodeSendMsgById(&(pMsg->destId), pSender->pSyncNode, &rpcMsg); - char *msgStr = syncSnapshotSend2Str(pMsg); char host[128]; uint16_t port; syncUtilU642Addr(pSender->pSyncNode->replicasId[pSender->replicaIndex].addr, host, sizeof(host), &port); - sTrace("sync event snapshot send to %s:%d begin seq:%d ack:%d lastApplyIndex:%ld lastApplyTerm:%lu send msg:%s", host, - port, pSender->seq, pSender->ack, pSender->snapshot.lastApplyIndex, pSender->snapshot.lastApplyTerm, msgStr); - taosMemoryFree(msgStr); + + if (gRaftDetailLog) { + char *msgStr = syncSnapshotSend2Str(pMsg); + sTrace( + "sync event vgId:%d snapshot send to %s:%d begin seq:%d ack:%d lastApplyIndex:%ld lastApplyTerm:%lu send " + "msg:%s", + pSender->pSyncNode->vgId, host, port, pSender->seq, pSender->ack, pSender->snapshot.lastApplyIndex, + pSender->snapshot.lastApplyTerm, msgStr); + taosMemoryFree(msgStr); + } else { + sTrace("sync event vgId:%d snapshot send to %s:%d begin seq:%d ack:%d lastApplyIndex:%ld lastApplyTerm:%lu", + pSender->pSyncNode->vgId, host, port, pSender->seq, pSender->ack, pSender->snapshot.lastApplyIndex, + pSender->snapshot.lastApplyTerm); + } syncSnapshotSendDestroy(pMsg); } @@ -183,9 +193,11 @@ void snapshotSenderStop(SSyncSnapshotSender *pSender) { pSender->start = false; - char *s = snapshotSender2Str(pSender); - sInfo("snapshotSenderStop %s", s); - taosMemoryFree(s); + if (gRaftDetailLog) { + char *s = snapshotSender2Str(pSender); + sInfo("snapshotSenderStop %s", s); + taosMemoryFree(s); + } } // when sender receiver ack, call this function to send msg from seq @@ -225,20 +237,29 @@ int32_t snapshotSend(SSyncSnapshotSender *pSender) { syncSnapshotSend2RpcMsg(pMsg, &rpcMsg); syncNodeSendMsgById(&(pMsg->destId), pSender->pSyncNode, &rpcMsg); - char *msgStr = syncSnapshotSend2Str(pMsg); char host[128]; uint16_t port; syncUtilU642Addr(pSender->pSyncNode->replicasId[pSender->replicaIndex].addr, host, sizeof(host), &port); + if (pSender->seq == SYNC_SNAPSHOT_SEQ_END) { - sTrace("sync event snapshot send to %s:%d finish seq:%d ack:%d lastApplyIndex:%ld lastApplyTerm:%lu send msg:%s", - host, port, pSender->seq, pSender->ack, pSender->snapshot.lastApplyIndex, pSender->snapshot.lastApplyTerm, - msgStr); + if (gRaftDetailLog) { + char *msgStr = syncSnapshotSend2Str(pMsg); + sTrace( + "sync event vgId:%d snapshot send to %s:%d finish seq:%d ack:%d lastApplyIndex:%ld lastApplyTerm:%lu send " + "msg:%s", + pSender->pSyncNode->vgId, host, port, pSender->seq, pSender->ack, pSender->snapshot.lastApplyIndex, + pSender->snapshot.lastApplyTerm, msgStr); + taosMemoryFree(msgStr); + } else { + sTrace("sync event vgId:%d snapshot send to %s:%d finish seq:%d ack:%d lastApplyIndex:%ld lastApplyTerm:%lu", + pSender->pSyncNode->vgId, host, port, pSender->seq, pSender->ack, pSender->snapshot.lastApplyIndex, + pSender->snapshot.lastApplyTerm); + } } else { - sTrace("sync event snapshot send to %s:%d sending seq:%d ack:%d lastApplyIndex:%ld lastApplyTerm:%lu send msg:%s", - host, port, pSender->seq, pSender->ack, pSender->snapshot.lastApplyIndex, pSender->snapshot.lastApplyTerm, - msgStr); + sTrace("sync event vgId:%d snapshot send to %s:%d sending seq:%d ack:%d lastApplyIndex:%ld lastApplyTerm:%lu", + pSender->pSyncNode->vgId, host, port, pSender->seq, pSender->ack, pSender->snapshot.lastApplyIndex, + pSender->snapshot.lastApplyTerm); } - taosMemoryFree(msgStr); syncSnapshotSendDestroy(pMsg); return 0; @@ -260,13 +281,19 @@ int32_t snapshotReSend(SSyncSnapshotSender *pSender) { syncSnapshotSend2RpcMsg(pMsg, &rpcMsg); syncNodeSendMsgById(&(pMsg->destId), pSender->pSyncNode, &rpcMsg); - char *msgStr = syncSnapshotSend2Str(pMsg); char host[128]; uint16_t port; syncUtilU642Addr(pSender->pSyncNode->replicasId[pSender->replicaIndex].addr, host, sizeof(host), &port); - sTrace("sync event snapshot send to %s:%d resend seq:%d ack:%d send msg:%s", host, port, pSender->seq, pSender->ack, - msgStr); - taosMemoryFree(msgStr); + + if (gRaftDetailLog) { + char *msgStr = syncSnapshotSend2Str(pMsg); + sTrace("sync event vgId:%d snapshot send to %s:%d resend seq:%d ack:%d send msg:%s", pSender->pSyncNode->vgId, + host, port, pSender->seq, pSender->ack, msgStr); + taosMemoryFree(msgStr); + } else { + sTrace("sync event vgId:%d snapshot send to %s:%d resend seq:%d ack:%d", pSender->pSyncNode->vgId, host, port, + pSender->seq, pSender->ack); + } syncSnapshotSendDestroy(pMsg); } @@ -331,7 +358,7 @@ char *snapshotSender2Str(SSyncSnapshotSender *pSender) { } // ------------------------------------- -SSyncSnapshotReceiver *snapshotReceiverCreate(SSyncNode *pSyncNode, int32_t replicaIndex) { +SSyncSnapshotReceiver *snapshotReceiverCreate(SSyncNode *pSyncNode, SRaftId fromId) { bool condition = (pSyncNode->pFsm->FpSnapshotStartWrite != NULL) && (pSyncNode->pFsm->FpSnapshotStopWrite != NULL) && (pSyncNode->pFsm->FpSnapshotDoWrite != NULL); @@ -345,7 +372,7 @@ SSyncSnapshotReceiver *snapshotReceiverCreate(SSyncNode *pSyncNode, int32_t repl pReceiver->ack = SYNC_SNAPSHOT_SEQ_BEGIN; pReceiver->pWriter = NULL; pReceiver->pSyncNode = pSyncNode; - pReceiver->replicaIndex = replicaIndex; + pReceiver->fromId = fromId; pReceiver->term = pSyncNode->pRaftStore->currentTerm; pReceiver->privateTerm = 0; @@ -365,10 +392,11 @@ void snapshotReceiverDestroy(SSyncSnapshotReceiver *pReceiver) { bool snapshotReceiverIsStart(SSyncSnapshotReceiver *pReceiver) { return pReceiver->start; } // begin receive snapshot msg (current term, seq begin) -static void snapshotReceiverDoStart(SSyncSnapshotReceiver *pReceiver, SyncTerm privateTerm) { +static void snapshotReceiverDoStart(SSyncSnapshotReceiver *pReceiver, SyncTerm privateTerm, SRaftId fromId) { pReceiver->term = pReceiver->pSyncNode->pRaftStore->currentTerm; pReceiver->privateTerm = privateTerm; pReceiver->ack = SYNC_SNAPSHOT_SEQ_BEGIN; + pReceiver->fromId = fromId; ASSERT(pReceiver->pWriter == NULL); int32_t ret = pReceiver->pSyncNode->pFsm->FpSnapshotStartWrite(pReceiver->pSyncNode->pFsm, &(pReceiver->pWriter)); @@ -377,14 +405,15 @@ static void snapshotReceiverDoStart(SSyncSnapshotReceiver *pReceiver, SyncTerm p // if receiver receive msg from seq = SYNC_SNAPSHOT_SEQ_BEGIN, start receiver // if already start, force close, start again -void snapshotReceiverStart(SSyncSnapshotReceiver *pReceiver, SyncTerm privateTerm) { +void snapshotReceiverStart(SSyncSnapshotReceiver *pReceiver, SyncTerm privateTerm, SRaftId fromId) { if (!snapshotReceiverIsStart(pReceiver)) { // start - snapshotReceiverDoStart(pReceiver, privateTerm); + snapshotReceiverDoStart(pReceiver, privateTerm, fromId); pReceiver->start = true; } else { // already start + sInfo("snapshot recv, receiver already start"); // force close, abandon incomplete data int32_t ret = @@ -393,15 +422,15 @@ void snapshotReceiverStart(SSyncSnapshotReceiver *pReceiver, SyncTerm privateTer pReceiver->pWriter = NULL; // start again - snapshotReceiverDoStart(pReceiver, privateTerm); + snapshotReceiverDoStart(pReceiver, privateTerm, fromId); pReceiver->start = true; - - ASSERT(0); } - char *s = snapshotReceiver2Str(pReceiver); - sInfo("snapshotReceiverStart %s", s); - taosMemoryFree(s); + if (gRaftDetailLog) { + char *s = snapshotReceiver2Str(pReceiver); + sInfo("snapshotReceiverStart %s", s); + taosMemoryFree(s); + } } void snapshotReceiverStop(SSyncSnapshotReceiver *pReceiver, bool apply) { @@ -418,9 +447,11 @@ void snapshotReceiverStop(SSyncSnapshotReceiver *pReceiver, bool apply) { ++(pReceiver->privateTerm); } - char *s = snapshotReceiver2Str(pReceiver); - sInfo("snapshotReceiverStop %s", s); - taosMemoryFree(s); + if (gRaftDetailLog) { + char *s = snapshotReceiver2Str(pReceiver); + sInfo("snapshotReceiverStop %s", s); + taosMemoryFree(s); + } } cJSON *snapshotReceiver2Json(SSyncSnapshotReceiver *pReceiver) { @@ -436,7 +467,22 @@ cJSON *snapshotReceiver2Json(SSyncSnapshotReceiver *pReceiver) { snprintf(u64buf, sizeof(u64buf), "%p", pReceiver->pSyncNode); cJSON_AddStringToObject(pRoot, "pSyncNode", u64buf); - cJSON_AddNumberToObject(pRoot, "replicaIndex", pReceiver->replicaIndex); + + cJSON *pFromId = cJSON_CreateObject(); + snprintf(u64buf, sizeof(u64buf), "%lu", pReceiver->fromId.addr); + cJSON_AddStringToObject(pFromId, "addr", u64buf); + { + uint64_t u64 = pReceiver->fromId.addr; + cJSON *pTmp = pFromId; + char host[128] = {0}; + uint16_t port; + syncUtilU642Addr(u64, host, sizeof(host), &port); + cJSON_AddStringToObject(pTmp, "addr_host", host); + cJSON_AddNumberToObject(pTmp, "addr_port", port); + } + cJSON_AddNumberToObject(pFromId, "vgId", pReceiver->fromId.vgId); + cJSON_AddItemToObject(pRoot, "fromId", pFromId); + snprintf(u64buf, sizeof(u64buf), "%lu", pReceiver->term); cJSON_AddStringToObject(pRoot, "term", u64buf); @@ -468,17 +514,23 @@ int32_t syncNodeOnSnapshotSendCb(SSyncNode *pSyncNode, SyncSnapshotSend *pMsg) { if (pMsg->term == pSyncNode->pRaftStore->currentTerm) { if (pMsg->seq == SYNC_SNAPSHOT_SEQ_BEGIN) { // begin - snapshotReceiverStart(pReceiver, pMsg->privateTerm); + snapshotReceiverStart(pReceiver, pMsg->privateTerm, pMsg->srcId); pReceiver->ack = pMsg->seq; needRsp = true; - char *msgStr = syncSnapshotSend2Str(pMsg); char host[128]; uint16_t port; syncUtilU642Addr(pMsg->srcId.addr, host, sizeof(host), &port); - sTrace("sync event snapshot recv from %s:%d begin ack:%d, lastIndex:%ld, lastTerm:%lu, recv msg:%s", host, port, - pReceiver->ack, pMsg->lastIndex, pMsg->lastTerm, msgStr); - taosMemoryFree(msgStr); + + if (gRaftDetailLog) { + char *msgStr = syncSnapshotSend2Str(pMsg); + sTrace("sync event vgId:%d snapshot recv from %s:%d begin ack:%d, lastIndex:%ld, lastTerm:%lu, recv msg:%s", + pSyncNode->vgId, host, port, pReceiver->ack, pMsg->lastIndex, pMsg->lastTerm, msgStr); + taosMemoryFree(msgStr); + } else { + sTrace("sync event vgId:%d snapshot recv from %s:%d begin ack:%d, lastIndex:%ld, lastTerm:%lu", + pSyncNode->vgId, host, port, pReceiver->ack, pMsg->lastIndex, pMsg->lastTerm); + } } else if (pMsg->seq == SYNC_SNAPSHOT_SEQ_END) { // end, finish FSM @@ -486,29 +538,46 @@ int32_t syncNodeOnSnapshotSendCb(SSyncNode *pSyncNode, SyncSnapshotSend *pMsg) { ASSERT(writeCode == 0); pSyncNode->pFsm->FpSnapshotStopWrite(pSyncNode->pFsm, pReceiver->pWriter, true); - pSyncNode->pLogStore->syncLogSetBeginIndex(pSyncNode->pLogStore, pMsg->lastIndex + 1); - char *logSimpleStr = logStoreSimple2Str(pSyncNode->pLogStore); + SSnapshot snapshot; pSyncNode->pFsm->FpGetSnapshot(pSyncNode->pFsm, &snapshot); + char host[128]; uint16_t port; syncUtilU642Addr(pMsg->srcId.addr, host, sizeof(host), &port); - sInfo( - "sync event snapshot recv from %s:%d finish, update log begin index:%ld, snapshot.lastApplyIndex:%ld, " - "snapshot.lastApplyTerm:%lu, raft log:%s", - host, port, pMsg->lastIndex + 1, snapshot.lastApplyIndex, snapshot.lastApplyTerm, logSimpleStr); - taosMemoryFree(logSimpleStr); + + if (gRaftDetailLog) { + char *logSimpleStr = logStoreSimple2Str(pSyncNode->pLogStore); + sInfo( + "sync event vgId:%d snapshot recv from %s:%d finish, update log begin index:%ld, " + "snapshot.lastApplyIndex:%ld, " + "snapshot.lastApplyTerm:%lu, raft log:%s", + pSyncNode->vgId, host, port, pMsg->lastIndex + 1, snapshot.lastApplyIndex, snapshot.lastApplyTerm, + logSimpleStr); + taosMemoryFree(logSimpleStr); + } else { + sInfo( + "sync event vgId:%d snapshot recv from %s:%d finish, update log begin index:%ld, " + "snapshot.lastApplyIndex:%ld, " + "snapshot.lastApplyTerm:%lu", + pSyncNode->vgId, host, port, pMsg->lastIndex + 1, snapshot.lastApplyIndex, snapshot.lastApplyTerm); + } pReceiver->pWriter = NULL; snapshotReceiverStop(pReceiver, true); pReceiver->ack = pMsg->seq; needRsp = true; - char *msgStr = syncSnapshotSend2Str(pMsg); - sTrace("sync event snapshot recv from %s:%d end ack:%d, lastIndex:%ld, lastTerm:%lu, recv msg:%s", host, port, - pReceiver->ack, pMsg->lastIndex, pMsg->lastTerm, msgStr); - taosMemoryFree(msgStr); + if (gRaftDetailLog) { + char *msgStr = syncSnapshotSend2Str(pMsg); + sTrace("sync event vgId:%d snapshot recv from %s:%d end ack:%d, lastIndex:%ld, lastTerm:%lu, recv msg:%s", + pReceiver->pSyncNode->vgId, host, port, pReceiver->ack, pMsg->lastIndex, pMsg->lastTerm, msgStr); + taosMemoryFree(msgStr); + } else { + sTrace("sync event vgId:%d snapshot recv from %s:%d end ack:%d, lastIndex:%ld, lastTerm:%lu", + pReceiver->pSyncNode->vgId, host, port, pReceiver->ack, pMsg->lastIndex, pMsg->lastTerm); + } } else if (pMsg->seq == SYNC_SNAPSHOT_SEQ_FORCE_CLOSE) { pSyncNode->pFsm->FpSnapshotStopWrite(pSyncNode->pFsm, pReceiver->pWriter, false); @@ -519,11 +588,17 @@ int32_t syncNodeOnSnapshotSendCb(SSyncNode *pSyncNode, SyncSnapshotSend *pMsg) { uint16_t port; syncUtilU642Addr(pMsg->srcId.addr, host, sizeof(host), &port); - char *msgStr = syncSnapshotSend2Str(pMsg); - sTrace("sync event snapshot recv from %s:%d force close ack:%d, lastIndex:%ld, lastTerm:%lu, recv msg:%s", host, - port, pReceiver->ack, pMsg->lastIndex, pMsg->lastTerm, msgStr); - - taosMemoryFree(msgStr); + if (gRaftDetailLog) { + char *msgStr = syncSnapshotSend2Str(pMsg); + sTrace( + "sync event vgId:%d snapshot recv from %s:%d force close ack:%d, lastIndex:%ld, lastTerm:%lu, recv " + "msg:%s", + pReceiver->pSyncNode->vgId, host, port, pReceiver->ack, pMsg->lastIndex, pMsg->lastTerm, msgStr); + taosMemoryFree(msgStr); + } else { + sTrace("sync event vgId:%d snapshot recv from %s:%d force close ack:%d, lastIndex:%ld, lastTerm:%lu", + pReceiver->pSyncNode->vgId, host, port, pReceiver->ack, pMsg->lastIndex, pMsg->lastTerm); + } } else if (pMsg->seq > SYNC_SNAPSHOT_SEQ_BEGIN && pMsg->seq < SYNC_SNAPSHOT_SEQ_END) { // transfering @@ -535,13 +610,20 @@ int32_t syncNodeOnSnapshotSendCb(SSyncNode *pSyncNode, SyncSnapshotSend *pMsg) { } needRsp = true; - char *msgStr = syncSnapshotSend2Str(pMsg); char host[128]; uint16_t port; syncUtilU642Addr(pMsg->srcId.addr, host, sizeof(host), &port); - sTrace("sync event snapshot recv from %s:%d receiving ack:%d, lastIndex:%ld, lastTerm:%lu, recv msg:%s", host, - port, pReceiver->ack, pMsg->lastIndex, pMsg->lastTerm, msgStr); - taosMemoryFree(msgStr); + + if (gRaftDetailLog) { + char *msgStr = syncSnapshotSend2Str(pMsg); + sTrace( + "sync event vgId:%d snapshot recv from %s:%d receiving ack:%d, lastIndex:%ld, lastTerm:%lu, recv msg:%s", + pSyncNode->vgId, host, port, pReceiver->ack, pMsg->lastIndex, pMsg->lastTerm, msgStr); + taosMemoryFree(msgStr); + } else { + sTrace("sync event vgId:%d snapshot recv from %s:%d receiving ack:%d, lastIndex:%ld, lastTerm:%lu", + pSyncNode->vgId, host, port, pReceiver->ack, pMsg->lastIndex, pMsg->lastTerm); + } } else { ASSERT(0); diff --git a/source/libs/sync/test/syncConfigChangeSnapshotTest.cpp b/source/libs/sync/test/syncConfigChangeSnapshotTest.cpp index 781c168da9fbe756f48c65e58cb48bad66b60d32..10b54d0aa492a8002762048f6c8e304df97dbfa5 100644 --- a/source/libs/sync/test/syncConfigChangeSnapshotTest.cpp +++ b/source/libs/sync/test/syncConfigChangeSnapshotTest.cpp @@ -146,7 +146,7 @@ int32_t SnapshotDoWrite(struct SSyncFSM* pFsm, void* pWriter, void* pBuf, int32_ void RestoreFinishCb(struct SSyncFSM* pFsm) { sTrace("==callback== ==RestoreFinishCb=="); } -void ReConfigCb(struct SSyncFSM* pFsm, SSyncCfg newCfg, SReConfigCbMeta cbMeta) { +void ReConfigCb(struct SSyncFSM* pFsm, const SRpcMsg* pMsg, SReConfigCbMeta cbMeta) { sTrace("==callback== ==ReConfigCb== flag:0x%lX, isDrop:%d, index:%ld, code:%d, currentTerm:%lu, term:%lu", cbMeta.flag, cbMeta.isDrop, cbMeta.index, cbMeta.code, cbMeta.currentTerm, cbMeta.term); } diff --git a/source/libs/sync/test/syncConfigChangeTest.cpp b/source/libs/sync/test/syncConfigChangeTest.cpp index c9d9ca48aa2c38de3a7c8c8ab280ab652cdc6e23..1e64a8a6f7b28e6caf1cd8ffc4dceffd4aadf345 100644 --- a/source/libs/sync/test/syncConfigChangeTest.cpp +++ b/source/libs/sync/test/syncConfigChangeTest.cpp @@ -77,7 +77,7 @@ int32_t GetSnapshotCb(struct SSyncFSM* pFsm, SSnapshot* pSnapshot) { void RestoreFinishCb(struct SSyncFSM* pFsm) { sTrace("==callback== ==RestoreFinishCb=="); } -void ReConfigCb(struct SSyncFSM* pFsm, SSyncCfg newCfg, SReConfigCbMeta cbMeta) { +void ReConfigCb(struct SSyncFSM* pFsm, const SRpcMsg* pMsg, SReConfigCbMeta cbMeta) { sTrace("==callback== ==ReConfigCb== flag:0x%lX, isDrop:%d, index:%ld, code:%d, currentTerm:%lu, term:%lu", cbMeta.flag, cbMeta.isDrop, cbMeta.index, cbMeta.code, cbMeta.currentTerm, cbMeta.term); } diff --git a/source/libs/sync/test/syncSnapshotReceiverTest.cpp b/source/libs/sync/test/syncSnapshotReceiverTest.cpp index 69670f09a666f4418eef2f5d9f455cc59a7fb8f2..208a96daa4560a557e31da218651d56fb10e8b3e 100644 --- a/source/libs/sync/test/syncSnapshotReceiverTest.cpp +++ b/source/libs/sync/test/syncSnapshotReceiverTest.cpp @@ -41,7 +41,11 @@ SSyncSnapshotReceiver* createReceiver() { pSyncNode->pFsm->FpSnapshotStopWrite = SnapshotStopWrite; pSyncNode->pFsm->FpSnapshotDoWrite = SnapshotDoWrite; - SSyncSnapshotReceiver* pReceiver = snapshotReceiverCreate(pSyncNode, 2); + SRaftId id; + id.addr = syncUtilAddr2U64("1.2.3.4", 99); + id.vgId = 100; + + SSyncSnapshotReceiver* pReceiver = snapshotReceiverCreate(pSyncNode, id); pReceiver->start = true; pReceiver->ack = 20; pReceiver->pWriter = (void*)0x11; diff --git a/source/libs/sync/test/syncTestTool.cpp b/source/libs/sync/test/syncTestTool.cpp index 782baf3c97ba7be843384bd827bfa8f9f26c7b12..0c8b26e9d9f2fa793acc6c103275a6c5737f503e 100644 --- a/source/libs/sync/test/syncTestTool.cpp +++ b/source/libs/sync/test/syncTestTool.cpp @@ -146,8 +146,8 @@ int32_t SnapshotDoWrite(struct SSyncFSM* pFsm, void* pWriter, void* pBuf, int32_ void RestoreFinishCb(struct SSyncFSM* pFsm) { sTrace("==callback== ==RestoreFinishCb== pFsm:%p", pFsm); } -void ReConfigCb(struct SSyncFSM* pFsm, SSyncCfg newCfg, SReConfigCbMeta cbMeta) { - char* s = syncCfg2Str(&newCfg); +void ReConfigCb(struct SSyncFSM* pFsm, const SRpcMsg* pMsg, SReConfigCbMeta cbMeta) { + char* s = syncCfg2Str(&(cbMeta.newCfg)); sTrace("==callback== ==ReConfigCb== flag:0x%lX, isDrop:%d, index:%ld, code:%d, currentTerm:%lu, term:%lu, newCfg:%s", cbMeta.flag, cbMeta.isDrop, cbMeta.index, cbMeta.code, cbMeta.currentTerm, cbMeta.term, s); taosMemoryFree(s); @@ -235,7 +235,6 @@ int64_t createSyncNode(int32_t replicaNum, int32_t myIndex, int32_t vgId, SWal* } } - int64_t rid = syncOpen(&syncInfo); assert(rid > 0);