Print block confirm latency when Peer Server stopped. (#23)

8 files changed, 67 insertions, 26 deletions

diff --git a/simulation/app.go b/simulation/app.go
index 34b53f4..b6851f8 100644
--- a/simulation/app.go
+++ b/simulation/app.go
@@ -19,6 +19,7 @@ package simulation
 
 import (
 	"fmt"
+	"time"
 
 	"github.com/dexon-foundation/dexon-consensus-core/common"
 	"github.com/dexon-foundation/dexon-consensus-core/core/types"
@@ -49,13 +50,27 @@ func (a *SimApp) ValidateBlock(b *types.Block) bool {
 
 // Deliver is called when blocks are delivered by the total ordering algorithm.
 func (a *SimApp) Deliver(blocks []*types.Block, early bool) {
+	now := time.Now()
 	a.Outputs = blocks
 	a.Early = early
 	fmt.Println("OUTPUT", a.ValidatorID, a.Early, a.Outputs)
+
 	blockHash := common.Hashes{}
+	confirmLatency := []time.Duration{}
+
 	for _, block := range blocks {
 		blockHash = append(blockHash, block.Hash)
+		if block.ProposerID == a.ValidatorID {
+			confirmLatency = append(confirmLatency,
+				now.Sub(block.Timestamps[a.ValidatorID]))
+		}
+	}
+
+	blockList := BlockList{
+		ID:             a.DeliverID,
+		BlockHash:      blockHash,
+		ConfirmLatency: confirmLatency,
 	}
-	a.Network.DeliverBlocks(blockHash, a.DeliverID)
+	a.Network.DeliverBlocks(blockList)
 	a.DeliverID++
 }
diff --git a/simulation/block-list.go b/simulation/block-list.go
index 5bf9f20..981bf3f 100644
--- a/simulation/block-list.go
+++ b/simulation/block-list.go
@@ -18,18 +18,22 @@
 package simulation
 
 import (
+	"time"
+
 	"github.com/dexon-foundation/dexon-consensus-core/common"
 )
 
 // BlockList is the list of blocks from the result of Total Ordering Algorithm.
 type BlockList struct {
-	ID        int           `json:"id"`
-	BlockHash common.Hashes `json:"blockhash"`
+	ID             int             `json:"id"`
+	BlockHash      common.Hashes   `json:"blockhash"`
+	ConfirmLatency []time.Duration `json:"confirmlatency"`
 	// The index is required by heap.Interface.
 	index int
 }
 
-// PendingBlockList is a PrioirtyQueue maintaining the BlockList received before the previous one (based on ID).
+// PendingBlockList is a PrioirtyQueue maintaining the BlockList received
+// before the previous one (based on ID).
 type PendingBlockList []*BlockList
 
 // Len, Less and Swap are implementing heap.Interface
diff --git a/simulation/fake-network.go b/simulation/fake-network.go
index dde8bd7..61394a9 100644
--- a/simulation/fake-network.go
+++ b/simulation/fake-network.go
@@ -22,7 +22,6 @@ import (
 	"sync"
 	"time"
 
-	"github.com/dexon-foundation/dexon-consensus-core/common"
 	"github.com/dexon-foundation/dexon-consensus-core/core/types"
 )
 
@@ -95,7 +94,7 @@ func (n *FakeNetwork) BroadcastBlock(block *types.Block) {
 }
 
 // DeliverBlocks sends blocks to peerServer.
-func (n *FakeNetwork) DeliverBlocks(blocks common.Hashes, id int) {
+func (n *FakeNetwork) DeliverBlocks(blocks BlockList) {
 	// TODO(jimmy-dexon): Implement this method.
 	return
 }
diff --git a/simulation/network.go b/simulation/network.go
index e69dd43..16e6918 100644
--- a/simulation/network.go
+++ b/simulation/network.go
@@ -20,7 +20,6 @@ package simulation
 import (
 	"encoding/json"
 
-	"github.com/dexon-foundation/dexon-consensus-core/common"
 	"github.com/dexon-foundation/dexon-consensus-core/core/types"
 )
 
@@ -65,7 +64,7 @@ type Network interface {
 
 // PeerServerNetwork is the interface for peerServer network related functions
 type PeerServerNetwork interface {
-	DeliverBlocks(blocks common.Hashes, id int)
+	DeliverBlocks(blocks BlockList)
 	NotifyServer(msg Message)
 	GetServerInfo() InfoMessage
 }
diff --git a/simulation/peer-server.go b/simulation/peer-server.go
index 1b8432f..4142158 100644
--- a/simulation/peer-server.go
+++ b/simulation/peer-server.go
@@ -76,7 +76,7 @@ func (p *PeerServer) Run(configPath string) {
 
 		host, _, _ := net.SplitHostPort(r.RemoteAddr)
 		p.peers[id] = net.JoinHostPort(host, portString)
-		p.peerTotalOrder[id] = NewTotalOrderResult()
+		p.peerTotalOrder[id] = NewTotalOrderResult(id)
 		log.Printf("Peer %s joined from %s", id, p.peers[id])
 	}
 
diff --git a/simulation/tcp-network.go b/simulation/tcp-network.go
index ff4de9e..911243f 100644
--- a/simulation/tcp-network.go
+++ b/simulation/tcp-network.go
@@ -28,7 +28,6 @@ import (
 	"sync"
 	"time"
 
-	"github.com/dexon-foundation/dexon-consensus-core/common"
 	"github.com/dexon-foundation/dexon-consensus-core/core/types"
 )
 
@@ -238,16 +237,10 @@ func (n *TCPNetwork) BroadcastBlock(block *types.Block) {
 }
 
 // DeliverBlocks sends blocks to peerServer.
-func (n *TCPNetwork) DeliverBlocks(blocks common.Hashes, id int) {
-
-	message := BlockList{
-		ID:        id,
-		BlockHash: blocks,
-	}
-
-	messageJSON, err := json.Marshal(message)
+func (n *TCPNetwork) DeliverBlocks(blocks BlockList) {
+	messageJSON, err := json.Marshal(blocks)
 	if err != nil {
-		fmt.Printf("error: failed to marshal json: %v\n%+v\n", err, message)
+		fmt.Printf("error: failed to marshal json: %v\n%+v\n", err, blocks)
 		return
 	}
 
diff --git a/simulation/validator.go b/simulation/validator.go
index 6ce5fa7..27e02fb 100644
--- a/simulation/validator.go
+++ b/simulation/validator.go
@@ -124,6 +124,12 @@ func (v *Validator) MsgServer() {
 	}
 }
 
+func (v *Validator) createBlockTimestamps() map[types.ValidatorID]time.Time {
+	timestamps := make(map[types.ValidatorID]time.Time)
+	timestamps[v.GetID()] = time.Now()
+	return timestamps
+}
+
 // BroadcastGenesisBlock broadcasts genesis block to all peers.
 func (v *Validator) BroadcastGenesisBlock() {
 	// Wait until all peer joined the network.
@@ -138,6 +144,7 @@ func (v *Validator) BroadcastGenesisBlock() {
 			ParentHash: hash,
 			Hash:       hash,
 			Height:     0,
+			Timestamps: v.createBlockTimestamps(),
 			Acks:       map[common.Hash]struct{}{},
 		}
 		v.genesis = b
@@ -171,6 +178,7 @@ ProposingBlockLoop:
 			ParentHash: v.current.Hash,
 			Hash:       common.NewRandomHash(),
 			Height:     v.current.Height + 1.,
+			Timestamps: v.createBlockTimestamps(),
 			Acks:       map[common.Hash]struct{}{},
 		}
 		v.current = block
diff --git a/simulation/verification.go b/simulation/verification.go
index bc1afc4..1f8947c 100644
--- a/simulation/verification.go
+++ b/simulation/verification.go
@@ -33,12 +33,14 @@ type timeStamp struct {
 }
 
 type totalOrderStatus struct {
-	blockReceive []timeStamp
+	blockReceive   []timeStamp
+	confirmLatency []time.Duration
 }
 
 // TotalOrderResult is the object maintaining peer's result of
 // Total Ordering Algorithm.
 type TotalOrderResult struct {
+	validatorID      types.ValidatorID
 	hashList         common.Hashes
 	curID            int
 	pendingBlockList PendingBlockList
@@ -49,20 +51,28 @@ type TotalOrderResult struct {
 type PeerTotalOrder = map[types.ValidatorID]*TotalOrderResult
 
 // NewTotalOrderResult returns pointer to a a new TotalOrderResult instance.
-func NewTotalOrderResult() *TotalOrderResult {
-	totalOrder := &TotalOrderResult{}
+func NewTotalOrderResult(vID types.ValidatorID) *TotalOrderResult {
+	totalOrder := &TotalOrderResult{
+		validatorID: vID,
+	}
 	heap.Init(&totalOrder.pendingBlockList)
 	return totalOrder
 }
 
-// PushBlocks push a BlockList into the TotalOrderResult and return true if
-// there is new blocks ready for verifiy
-func (totalOrder *TotalOrderResult) PushBlocks(blocks BlockList) (ready bool) {
+func (totalOrder *TotalOrderResult) processStatus(blocks BlockList) {
 	totalOrder.status.blockReceive = append(totalOrder.status.blockReceive,
 		timeStamp{
 			time:   time.Now(),
 			length: len(blocks.BlockHash),
 		})
+	totalOrder.status.confirmLatency = append(totalOrder.status.confirmLatency,
+		blocks.ConfirmLatency...)
+}
+
+// PushBlocks push a BlockList into the TotalOrderResult and return true if
+// there is new blocks ready for verifiy
+func (totalOrder *TotalOrderResult) PushBlocks(blocks BlockList) (ready bool) {
+	totalOrder.processStatus(blocks)
 	if blocks.ID != totalOrder.curID {
 		heap.Push(&totalOrder.pendingBlockList, &blocks)
 		return false
@@ -103,6 +113,16 @@ func (totalOrder *TotalOrderResult) CalculateBlocksPerSecond() float64 {
 	return float64(totalBlocks) / diffTime
 }
 
+// CalculateAverageConfirmLatency calculates the result using
+// status.confirmLatency
+func (totalOrder *TotalOrderResult) CalculateAverageConfirmLatency() float64 {
+	sum := 0.0
+	for _, latency := range totalOrder.status.confirmLatency {
+		sum += latency.Seconds()
+	}
+	return sum / float64(len(totalOrder.status.confirmLatency))
+}
+
 // VerifyTotalOrder verifies if the result of Total Ordering Algorithm
 // returned by all validators are the same. However, the length of result
 // of each validators may not be the same, so only the common part is verified.
@@ -151,6 +171,9 @@ func VerifyTotalOrder(id types.ValidatorID,
 // LogStatus prints all the status to log.
 func LogStatus(peerTotalOrder PeerTotalOrder) {
 	for vID, totalOrder := range peerTotalOrder {
-		log.Printf("[Validator %s] BPS: %.6f\n", vID, totalOrder.CalculateBlocksPerSecond())
+		log.Printf("[Validator %s] BPS: %.6f\n",
+			vID, totalOrder.CalculateBlocksPerSecond())
+		log.Printf("[Validator %s] Confirm Latency: %.3fs\n",
+			vID, totalOrder.CalculateAverageConfirmLatency())
 	}
 }