chore: Better database query logs and logarithmic scale in grafana st…

…ore panels (#3048)
waku-org · Sep 20, 2024 · e492c59 · e492c59
1 parent bbebbf6
commit e492c59
Show file tree

Hide file tree

Showing 4 changed files with 73 additions and 85 deletions.
diff --git a/metrics/waku-fleet-dashboard.json b/metrics/waku-fleet-dashboard.json
@@ -3948,7 +3948,8 @@
             "lineWidth": 2,
             "pointSize": 10,
             "scaleDistribution": {
-              "type": "linear"
+              "log": 10,
+              "type": "log"
             },
             "showPoints": "auto",
             "spanNulls": false,
@@ -3973,7 +3974,32 @@
           },
           "unit": "s"
         },
-        "overrides": []
+        "overrides": [
+          {
+            "__systemRef": "hideSeriesFrom",
+            "matcher": {
+              "id": "byNames",
+              "options": {
+                "mode": "exclude",
+                "names": [
+                  "query_tag_ANALYZEmessages"
+                ],
+                "prefix": "All except:",
+                "readOnly": true
+              }
+            },
+            "properties": [
+              {
+                "id": "custom.hideFrom",
+                "value": {
+                  "legend": false,
+                  "tooltip": false,
+                  "viz": true
+                }
+              }
+            ]
+          }
+        ]
       },
       "gridPos": {
         "h": 11,
@@ -4048,7 +4074,8 @@
             "lineWidth": 2,
             "pointSize": 10,
             "scaleDistribution": {
-              "type": "linear"
+              "log": 10,
+              "type": "log"
             },
             "showPoints": "auto",
             "spanNulls": false,
@@ -4109,6 +4136,7 @@
           "editorMode": "code",
           "exemplar": true,
           "expr": "query_time_secs{instance=~\"[[host]].([[dc:pipe]]).([[fleet:pipe]])\", phase=\"waitFinish\"} and deriv(query_time_secs{instance=~\"[[host]].([[dc:pipe]]).([[fleet:pipe]])\", phase=\"waitFinish\"}[45s]) != 0",
+          "hide": false,
           "interval": "",
           "legendFormat": "{{query}}",
           "range": true,
@@ -4147,7 +4175,8 @@
             "lineWidth": 2,
             "pointSize": 10,
             "scaleDistribution": {
-              "type": "linear"
+              "log": 10,
+              "type": "log"
             },
             "showPoints": "auto",
             "spanNulls": false,
@@ -4246,7 +4275,8 @@
             "lineWidth": 2,
             "pointSize": 10,
             "scaleDistribution": {
-              "type": "linear"
+              "log": 10,
+              "type": "log"
             },
             "showPoints": "auto",
             "spanNulls": false,
@@ -5456,8 +5486,7 @@
             "mode": "absolute",
             "steps": [
               {
-                "color": "green",
-                "value": null
+                "color": "green"
               },
               {
                 "color": "red",
@@ -5551,8 +5580,7 @@
             "mode": "absolute",
             "steps": [
               {
-                "color": "green",
-                "value": null
+                "color": "green"
               },
               {
                 "color": "red",
@@ -5643,8 +5671,7 @@
             "mode": "absolute",
             "steps": [
               {
-                "color": "green",
-                "value": null
+                "color": "green"
               },
               {
                 "color": "red",
@@ -5897,8 +5924,7 @@
             "mode": "absolute",
             "steps": [
               {
-                "color": "green",
-                "value": null
+                "color": "green"
               },
               {
                 "color": "red",
@@ -6022,8 +6048,7 @@
             "mode": "absolute",
             "steps": [
               {
-                "color": "green",
-                "value": null
+                "color": "green"
               },
               {
                 "color": "red",
@@ -7346,7 +7371,7 @@
       "type": "row"
     }
   ],
-  "refresh": "30s",
+  "refresh": false,
   "schemaVersion": 37,
   "style": "dark",
   "tags": [],
@@ -7428,10 +7453,10 @@
         "current": {
           "selected": true,
           "text": [
-            "All"
+            "ac-cn-hongkong-c"
           ],
           "value": [
-            "$__all"
+            "ac-cn-hongkong-c"
           ]
         },
         "datasource": {
@@ -7461,8 +7486,8 @@
     ]
   },
   "time": {
-    "from": "now-24h",
-    "to": "now"
+    "from": "2024-09-20T12:34:03.849Z",
+    "to": "2024-09-20T13:52:30.721Z"
   },
   "timepicker": {
     "refresh_intervals": [
@@ -7480,6 +7505,6 @@
   "timezone": "browser",
   "title": "Nim-Waku V2",
   "uid": "qrp_ZCTGz",
-  "version": 150,
+  "version": 151,
   "weekStart": ""
 }
diff --git a/waku/common/databases/db_postgres/dbconn.nim b/waku/common/databases/db_postgres/dbconn.nim
@@ -1,4 +1,10 @@
-import std/[times, strutils, asyncnet, os, sequtils], results, chronos, metrics, re
+import
+  std/[times, strutils, asyncnet, os, sequtils],
+  results,
+  chronos,
+  metrics,
+  re,
+  chronicles
 import ./query_metrics
 
 include db_connector/db_postgres
@@ -167,21 +173,26 @@ proc dbConnQuery*(
   (await db.sendQuery(query, args)).isOkOr:
     return err("error in dbConnQuery calling sendQuery: " & $error)
 
-  query_time_secs.set(
-    getTime().toUnixFloat() - queryStartTime, [querySummary, "sendQuery"]
-  )
+  let sendDuration = getTime().toUnixFloat() - queryStartTime
+  query_time_secs.set(sendDuration, [querySummary, "sendQuery"])
 
   queryStartTime = getTime().toUnixFloat()
 
   (await db.waitQueryToFinish(rowCallback)).isOkOr:
     return err("error in dbConnQuery calling waitQueryToFinish: " & $error)
 
-  query_time_secs.set(
-    getTime().toUnixFloat() - queryStartTime, [querySummary, "waitFinish"]
-  )
+  let waitDuration = getTime().toUnixFloat() - queryStartTime
+  query_time_secs.set(waitDuration, [querySummary, "waitFinish"])
 
   query_count.inc(labelValues = [querySummary])
 
+  if "insert" notin ($query).toLower():
+    debug "dbConnQuery",
+      query = $query,
+      querySummary,
+      waitDurationSecs = waitDuration,
+      sendDurationSecs = sendDuration
+
   return ok()
 
 proc dbConnQueryPrepared*(
@@ -196,17 +207,21 @@ proc dbConnQueryPrepared*(
   db.sendQueryPrepared(stmtName, paramValues, paramLengths, paramFormats).isOkOr:
     return err("error in dbConnQueryPrepared calling sendQuery: " & $error)
 
-  query_time_secs.set(getTime().toUnixFloat() - queryStartTime, [stmtName, "sendQuery"])
+  let sendDuration = getTime().toUnixFloat() - queryStartTime
+  query_time_secs.set(sendDuration, [stmtName, "sendQuery"])
 
   queryStartTime = getTime().toUnixFloat()
 
   (await db.waitQueryToFinish(rowCallback)).isOkOr:
     return err("error in dbConnQueryPrepared calling waitQueryToFinish: " & $error)
 
-  query_time_secs.set(
-    getTime().toUnixFloat() - queryStartTime, [stmtName, "waitFinish"]
-  )
+  let waitDuration = getTime().toUnixFloat() - queryStartTime
+  query_time_secs.set(waitDuration, [stmtName, "waitFinish"])
 
   query_count.inc(labelValues = [stmtName])
 
+  if "insert" notin stmtName.toLower():
+    debug "dbConnQueryPrepared",
+      stmtName, waitDurationSecs = waitDuration, sendDurationSecs = sendDuration
+
   return ok()