From 7763df95a4ee6a223a987f12e04307d7e5309b5e Mon Sep 17 00:00:00 2001
From: =?UTF-8?q?=C8=98tefan=20Talpalaru?= <stefantalpalaru@yahoo.com>
Date: Mon, 10 Aug 2020 19:10:43 +0200
Subject: [PATCH] storeBlock() duration metric (#1480)

---
 beacon_chain/beacon_node.nim                | 11 ++-
 grafana/beacon_nodes_Grafana_dashboard.json | 82 +++++++++++++++++++--
 2 files changed, 83 insertions(+), 10 deletions(-)

diff --git a/beacon_chain/beacon_node.nim b/beacon_chain/beacon_node.nim
index 6b86b0b50..2161ac59c 100644
--- a/beacon_chain/beacon_node.nim
+++ b/beacon_chain/beacon_node.nim
@@ -68,10 +68,13 @@ declareGauge finalization_delay,
 const delayBuckets = [2.0, 4.0, 6.0, 8.0, 10.0, 12.0, 14.0, Inf]
 
 declareHistogram beacon_attestation_received_seconds_from_slot_start,
-  "Interval between slot start and attestation receival", buckets = delayBuckets
+  "Interval between slot start and attestation reception", buckets = delayBuckets
 
 declareHistogram beacon_block_received_seconds_from_slot_start,
-  "Interval between slot start and beacon block receival", buckets = delayBuckets
+  "Interval between slot start and beacon block reception", buckets = delayBuckets
+
+declareHistogram beacon_store_block_duration_seconds,
+  "storeBlock() duration", buckets = [0.25, 0.5, 1, 2, 4, 8, Inf]
 
 logScope: topics = "beacnde"
 
@@ -337,6 +340,7 @@ proc dumpBlock[T](
 
 proc storeBlock(
     node: BeaconNode, signedBlock: SignedBeaconBlock): Result[void, BlockError] =
+  let start = Moment.now()
   debug "Block received",
     signedBlock = shortLog(signedBlock.message),
     blockRoot = shortLog(signedBlock.root),
@@ -362,7 +366,8 @@ proc storeBlock(
   if blck.isErr:
     return err(blck.error)
 
-  ok()
+  beacon_store_block_duration_seconds.observe((Moment.now() - start).milliseconds.float64 / 1000)
+  return ok()
 
 proc onBeaconBlock(node: BeaconNode, signedBlock: SignedBeaconBlock) =
   # We received a block but don't know much about it yet - in particular, we
diff --git a/grafana/beacon_nodes_Grafana_dashboard.json b/grafana/beacon_nodes_Grafana_dashboard.json
index be6a88c76..bf6c1e45a 100644
--- a/grafana/beacon_nodes_Grafana_dashboard.json
+++ b/grafana/beacon_nodes_Grafana_dashboard.json
@@ -1989,6 +1989,74 @@
       "yBucketNumber": null,
       "yBucketSize": null
     },
+    {
+      "cards": {
+        "cardPadding": null,
+        "cardRound": null
+      },
+      "color": {
+        "cardColor": "#b4ff00",
+        "colorScale": "sqrt",
+        "colorScheme": "interpolateSpectral",
+        "exponent": 0.1,
+        "max": null,
+        "min": 0,
+        "mode": "opacity"
+      },
+      "dataFormat": "tsbuckets",
+      "datasource": null,
+      "gridPos": {
+        "h": 6,
+        "w": 14,
+        "x": 0,
+        "y": 53
+      },
+      "heatmap": {},
+      "hideZeroBuckets": false,
+      "highlightCards": true,
+      "id": 50,
+      "interval": "",
+      "legend": {
+        "show": false
+      },
+      "reverseYBuckets": false,
+      "targets": [
+        {
+          "expr": "rate(beacon_store_block_duration_seconds_bucket{node=\"${node}\"}[4s]) * 3",
+          "format": "heatmap",
+          "instant": false,
+          "interval": "",
+          "intervalFactor": 1,
+          "legendFormat": "{{le}}",
+          "refId": "A"
+        }
+      ],
+      "timeFrom": null,
+      "timeShift": null,
+      "title": "storeBlock() duration (s) #${node}",
+      "tooltip": {
+        "show": true,
+        "showHistogram": false
+      },
+      "type": "heatmap",
+      "xAxis": {
+        "show": true
+      },
+      "xBucketNumber": null,
+      "xBucketSize": null,
+      "yAxis": {
+        "decimals": null,
+        "format": "short",
+        "logBase": 1,
+        "max": null,
+        "min": null,
+        "show": true,
+        "splitFactor": null
+      },
+      "yBucketBound": "auto",
+      "yBucketNumber": null,
+      "yBucketSize": null
+    },
     {
       "aliasColors": {},
       "bars": false,
@@ -2001,7 +2069,7 @@
         "h": 6,
         "w": 14,
         "x": 0,
-        "y": 53
+        "y": 59
       },
       "hiddenSeries": false,
       "id": 45,
@@ -2094,7 +2162,7 @@
         "h": 15,
         "w": 14,
         "x": 0,
-        "y": 59
+        "y": 65
       },
       "hiddenSeries": false,
       "id": 46,
@@ -2187,7 +2255,7 @@
         "h": 6,
         "w": 14,
         "x": 0,
-        "y": 74
+        "y": 80
       },
       "hiddenSeries": false,
       "id": 47,
@@ -2280,7 +2348,7 @@
         "h": 6,
         "w": 14,
         "x": 0,
-        "y": 80
+        "y": 86
       },
       "hiddenSeries": false,
       "id": 48,
@@ -2373,7 +2441,7 @@
         "h": 11,
         "w": 14,
         "x": 0,
-        "y": 86
+        "y": 92
       },
       "hiddenSeries": false,
       "id": 49,
@@ -2491,7 +2559,7 @@
     ]
   },
   "time": {
-    "from": "now-30m",
+    "from": "now-1h",
     "to": "now"
   },
   "timepicker": {
@@ -2514,5 +2582,5 @@
   "variables": {
     "list": []
   },
-  "version": 10
+  "version": 15
 }