print timings

build.nims

@@ -7,7 +7,7 @@ proc buildBinary(name: string, srcDir = "./", params = "", lang = "c") =
     mkDir "build"
   # allow something like "nim nimbus --verbosity:0 --hints:off nimbus.nims"
   var extra_params = params
-  when compiles(commandLineParams):
+  when compiles(commandLineParams()):
     for param in commandLineParams():
       extra_params &= " " & param
   else:

config.nims

@@ -4,6 +4,8 @@ include "build.nims"
 import std/os
 const currentDir = currentSourcePath()[0 .. ^(len("config.nims") + 1)]
 
+--d:chronosClosureDurationMetric
+
 when getEnv("NIMBUS_BUILD_SYSTEM") == "yes" and
    # BEWARE
    # In Nim 1.6, config files are evaluated with a working directory

tests/testCodex.nim

@@ -17,3 +17,31 @@ import ./codex/testvalidation
 import ./codex/testasyncstreamwrapper
 
 {.warning[UnusedImport]: off.}
+
+when isMainModule and defined(chronosClosureDurationMetric):
+  import std/tables
+  import chronos
+
+  let metrics = getCallbackDurations()
+  echo "\ncsv timings print: "
+  echo "file, ", "line, ", "procedure, ", "count, ", "avg micros, ", "min, ", "max, ", "total "
+
+  for (k,v) in metrics.pairs():
+    if v.count > 0:
+      let avgMicros = microseconds(v.totalDuration div v.count)
+      let minMicros = microseconds(v.minSingleTime)
+      let maxMicros = microseconds(v.maxSingleTime)
+      let totalMicros = microseconds(v.totalDuration)
+      echo  k.file, ", ", k.line, ", ", k.procedure, ", ", v.count, ", ",
+              avgMicros, ", ", minMicros, ", ", maxMicros, ", ", totalMicros
+
+  echo "\nflat print: "
+  for (k,v) in metrics.pairs():
+    if v.count > 0:
+      echo ""
+      echo "metric: ", $k
+      echo "count: ", v.count
+      echo "min: ", v.minSingleTime
+      echo "avg: ", v.totalDuration div v.count
+      echo "max: ", v.maxSingleTime
+      echo "total: ", v.totalDuration

tests/testIntegration.nim

@@ -3,3 +3,31 @@ import ./integration/testblockexpiration
 import ./integration/testproofs
 
 {.warning[UnusedImport]:off.}
+
+when isMainModule and defined(chronosClosureDurationMetric):
+  import std/tables
+  import chronos
+
+  let metrics = getCallbackDurations()
+  echo "\ncsv timings print: "
+  echo "file, ", "line, ", "procedure, ", "count, ", "avg micros, ", "min, ", "max, ", "total "
+
+  for (k,v) in metrics.pairs():
+    if v.count > 0:
+      let avgMicros = microseconds(v.totalDuration div v.count)
+      let minMicros = microseconds(v.minSingleTime)
+      let maxMicros = microseconds(v.maxSingleTime)
+      let totalMicros = microseconds(v.totalDuration)
+      echo  k.file, ", ", k.line, ", ", k.procedure, ", ", v.count, ", ",
+              avgMicros, ", ", minMicros, ", ", maxMicros, ", ", totalMicros
+
+  echo "\nflat print: "
+  for (k,v) in metrics.pairs():
+    if v.count > 0:
+      echo ""
+      echo "metric: ", $k
+      echo "count: ", v.count
+      echo "min: ", v.minSingleTime
+      echo "avg: ", v.totalDuration div v.count
+      echo "max: ", v.maxSingleTime
+      echo "total: ", v.totalDuration

vendor/nim-chronos

@@ -1 +1 @@
-Subproject commit 0277b65be2c7a365ac13df002fba6e172be55537
+Subproject commit 260f3610fe2ff8dc19e52dad4529cea568ea4151