core: refine DKG aborting (#512)

* Avoid aborting the DKG protocol registered later

Although that DKG protocol would be registered after
1/2 round, both of them are triggered in separated
go routine and we shouldn't assuem their execution order.

* Capitalize logs

* Add test

* Return aborted when not running

* Log DKG aborting result

* Remove duplicated DKG abort

2 files changed, 17 insertions, 17 deletions

diff --git a/core/syncer/agreement.go b/core/syncer/agreement.go
index 9f1abca..f172b3b 100644
--- a/core/syncer/agreement.go
+++ b/core/syncer/agreement.go
@@ -103,7 +103,7 @@ func (a *agreement) processBlock(b *types.Block) {
 func (a *agreement) processAgreementResult(r *types.AgreementResult) {
 	// Cache those results that CRS is not ready yet.
 	if _, exists := a.confirmedBlocks[r.BlockHash]; exists {
-		a.logger.Trace("agreement result already confirmed", "result", r)
+		a.logger.Trace("Agreement result already confirmed", "result", r)
 		return
 	}
 	if r.Position.Round > a.latestCRSRound {
@@ -113,11 +113,11 @@ func (a *agreement) processAgreementResult(r *types.AgreementResult) {
 			a.pendings[r.Position.Round] = pendingsForRound
 		}
 		pendingsForRound[r.BlockHash] = r
-		a.logger.Trace("agreement result cached", "result", r)
+		a.logger.Trace("Agreement result cached", "result", r)
 		return
 	}
 	if err := core.VerifyAgreementResult(r, a.cache); err != nil {
-		a.logger.Error("agreement result verification failed",
+		a.logger.Error("Agreement result verification failed",
 			"result", r,
 			"error", err)
 		return
@@ -144,12 +144,12 @@ loop:
 		case a.pullChan <- r.BlockHash:
 			break loop
 		case <-a.ctx.Done():
-			a.logger.Error("pull request is not sent",
+			a.logger.Error("Pull request is not sent",
 				"position", &r.Position,
 				"hash", r.BlockHash.String()[:6])
 			return
 		case <-time.After(500 * time.Millisecond):
-			a.logger.Debug("pull request is unable to send",
+			a.logger.Debug("Pull request is unable to send",
 				"position", &r.Position,
 				"hash", r.BlockHash.String()[:6])
 		}
@@ -171,12 +171,12 @@ func (a *agreement) processNewCRS(round uint64) {
 		delete(a.pendings, r)
 		for _, res := range pendingsForRound {
 			if err := core.VerifyAgreementResult(res, a.cache); err != nil {
-				a.logger.Error("invalid agreement result",
+				a.logger.Error("Invalid agreement result",
 					"result", res,
 					"error", err)
 				continue
 			}
-			a.logger.Error("flush agreement result", "result", res)
+			a.logger.Error("Flush agreement result", "result", res)
 			a.processAgreementResult(res)
 			break
 		}
@@ -194,10 +194,10 @@ func (a *agreement) confirm(b *types.Block) {
 			case a.outputChan <- b:
 				break loop
 			case <-a.ctx.Done():
-				a.logger.Error("confirmed block is not sent", "block", b)
+				a.logger.Error("Confirmed block is not sent", "block", b)
 				return
 			case <-time.After(500 * time.Millisecond):
-				a.logger.Debug("agreement output channel is full", "block", b)
+				a.logger.Debug("Agreement output channel is full", "block", b)
 			}
 		}
 		a.confirmedBlocks[b.Hash] = struct{}{}
diff --git a/core/syncer/consensus.go b/core/syncer/consensus.go
index d05651e..24c781a 100644
--- a/core/syncer/consensus.go
+++ b/core/syncer/consensus.go
@@ -191,7 +191,7 @@ func (con *Consensus) assureBuffering() {
 						return false
 					case <-time.After(500 * time.Millisecond):
 						con.logger.Warn(
-							"agreement input channel is full when notifying new round",
+							"Agreement input channel is full when notifying new round",
 							"round", e.Round,
 						)
 						return true
@@ -217,7 +217,7 @@ func (con *Consensus) checkIfSynced(blocks []*types.Block) (synced bool) {
 	con.lock.RLock()
 	defer con.lock.RUnlock()
 	defer func() {
-		con.logger.Debug("syncer synced status",
+		con.logger.Debug("Syncer synced status",
 			"last-block", blocks[len(blocks)-1],
 			"synced", synced,
 		)
@@ -303,14 +303,14 @@ func (con *Consensus) SyncBlocks(
 	// tip in DB.
 	_, tipHeight := con.db.GetCompactionChainTipInfo()
 	if blocks[0].Finalization.Height != tipHeight+1 {
-		con.logger.Error("mismatched finalization height",
+		con.logger.Error("Mismatched finalization height",
 			"now", blocks[0].Finalization.Height,
 			"expected", tipHeight+1,
 		)
 		err = ErrInvalidSyncingFinalizationHeight
 		return
 	}
-	con.logger.Trace("syncBlocks",
+	con.logger.Trace("SyncBlocks",
 		"position", &blocks[0].Position,
 		"final height", blocks[0].Finalization.Height,
 		"len", len(blocks),
@@ -404,14 +404,14 @@ func (con *Consensus) stopBuffering() {
 			return
 		}
 		con.duringBuffering = false
-		con.logger.Trace("syncer is about to stop")
+		con.logger.Trace("Syncer is about to stop")
 		// Stop network and CRS routines, wait until they are all stoped.
 		con.ctxCancel()
 		return
 	}() {
 		return
 	}
-	con.logger.Trace("stop syncer modules")
+	con.logger.Trace("Stop syncer modules")
 	con.roundEvt.Stop()
 	con.waitGroup.Done()
 	// Wait for all routines depends on con.agreementModule stopped.
@@ -424,9 +424,9 @@ func (con *Consensus) stopBuffering() {
 			con.dummyMsgBuffer = append(con.dummyMsgBuffer, msg)
 		})
 	// Stop agreements.
-	con.logger.Trace("stop syncer agreement modules")
+	con.logger.Trace("Stop syncer agreement modules")
 	con.stopAgreement()
-	con.logger.Trace("syncer stopped")
+	con.logger.Trace("Syncer stopped")
 	return
 }