archive perf test

buildkite/scripts/bench/run.sh

@@ -15,6 +15,11 @@ MAINLINE_BRANCHES="-m develop -m compatible -m master -m dkijania/bench_for_ledg
 while [[ "$#" -gt 0 ]]; do case $1 in
   heap-usage) BENCHMARK="heap-usage"; ;;
   mina-base) BENCHMARK="mina-base"; ;;
+  archive) 
+    BENCHMARK="archive"; 
+    EXTRA_ARGS="--no-run ${EXTRA_ARGS}" 
+
+  ;;
   ledger-export) 
     BENCHMARK="ledger-export"
     EXTRA_ARGS="--genesis-ledger-path ./genesis_ledgers/devnet.json"

buildkite/src/Command/ArchiveNodeTest.dhall

@@ -26,7 +26,7 @@ in  { step =
                         , buildFlags = BuildFlags.Type.Instrumented
                         }
                     )
-                    "./scripts/tests/archive-node-test.sh && buildkite/scripts/upload-partial-coverage-data.sh ${key}"
+                    "./scripts/tests/archive-node-test.sh && buildkite/scripts/upload-partial-coverage-data.sh ${key} && ls -al && ./buildkite/scripts/cache/manager.sh write archive.perf archive-node-test"
                 ]
               , label = "Archive: Node Test"
               , key = key

buildkite/src/Command/Bench/Archive.dhall

@@ -0,0 +1,43 @@
+let BenchBase = ../../Command/Bench/Base.dhall
+
+let SelectFiles = ../../Lib/SelectFiles.dhall
+
+let Pipeline = ../../Pipeline/Dsl.dhall
+
+let PipelineScope = ../../Pipeline/Scope.dhall
+
+let Cmd = ../../Lib/Cmds.dhall
+
+let makeArchiveBench =
+          \(name : Text)
+      ->  \(scope : List PipelineScope.Type)
+      ->  Pipeline.build
+            ( BenchBase.pipeline
+                BenchBase.Spec::{
+                , additionalDirtyWhen =
+                  [ SelectFiles.strictlyStart
+                      (SelectFiles.contains "src/test/archive")
+                  , SelectFiles.exactly
+                      "buildkite/src/Jobs/Bench/ArchiveStable"
+                      "dhall"
+                  , SelectFiles.exactly
+                      "buildkite/src/Jobs/Bench/ArchiveUnstable"
+                      "dhall"
+                  ]
+                , path = "Bench"
+                , name = name
+                , label = "Archive"
+                , key = "archive-perf"
+                , bench = "archive"
+                , dependsOn =
+                  [ { name = "ArchiveNodeTest", key = "archive-node-test" } ]
+                , preCommands =
+                  [ Cmd.run
+                      "./buildkite/scripts/cache/manager.sh read archive-node-test/archive.perf ."
+                  ]
+                , scope = scope
+                , extraArgs = "--input-file archive.perf"
+                }
+            )
+
+in  { makeArchiveBench = makeArchiveBench }

buildkite/src/Command/Bench/Base.dhall

@@ -41,6 +41,7 @@ let Spec =
           , yellowThreshold : Double
           , redThreshold : Double
           , preCommands : List Cmd.Type
+          , extraArgs : Text
           , scope : List PipelineScope.Type
           }
       , default =
@@ -55,6 +56,7 @@ let Spec =
           , yellowThreshold = 0.1
           , redThreshold = 0.2
           , preCommands = [] : List Cmd.Type
+          , extraArgs = ""
           }
       }
 
@@ -70,9 +72,9 @@ let command
                       # [ "BRANCH=\\\${BUILDKITE_PULL_REQUEST_BASE_BRANCH:-BUILDKITE_BRANCH}"
                         ]
                     )
-                    "./buildkite/scripts/bench/run.sh  ${spec.bench} --red-threshold ${Double/show
-                                                                                         spec.redThreshold} --yellow-threshold ${Double/show
-                                                                                                                                   spec.yellowThreshold}"
+                    "EXTRA_ARGS=\"${spec.extraArgs}\" ./buildkite/scripts/bench/run.sh  ${spec.bench} --red-threshold ${Double/show
+                                                                                                                          spec.redThreshold} --yellow-threshold ${Double/show
+                                                                                                                                                                    spec.yellowThreshold}"
             , label = "Perf: ${spec.label}"
             , key = spec.key
             , target = spec.size

buildkite/src/Jobs/Bench/ArchiveStable.dhall

@@ -0,0 +1,7 @@
+let ArchiveBench = ../../Command/Bench/Archive.dhall
+
+let PipelineScope = ../../Pipeline/Scope.dhall
+
+in  ArchiveBench.makeArchiveBench
+      "ArchiveStable"
+      PipelineScope.AllButPullRequest

buildkite/src/Jobs/Bench/ArchiveUnstable.dhall

@@ -0,0 +1,7 @@
+let ArchiveBench = ../../Command/Bench/Archive.dhall
+
+let PipelineScope = ../../Pipeline/Scope.dhall
+
+in  ArchiveBench.makeArchiveBench
+      "ArchiveUnstable"
+      PipelineScope.PullRequestOnly

buildkite/src/Jobs/Test/ArchiveNodeTest.dhall

@@ -12,13 +12,13 @@ let Artifacts = ../../Constants/Artifacts.dhall
 
 let Dockers = ../../Constants/DockerVersions.dhall
 
-let buildFlags = ../../Constants/BuildFlags.dhall
+let BuildFlags = ../../Constants/BuildFlags.dhall
 
 let dependsOn =
       Dockers.dependsOn
         Dockers.DepsSpec::{
+        , buildFlags = BuildFlags.Type.Instrumented
         , artifact = Artifacts.Type.FunctionalTestSuite
-        , buildFlags = buildFlags.Type.Instrumented
         }
 
 in  Pipeline.build

changes/17522.md

@@ -0,0 +1 @@
+Enhanced precomputed_blocks test with performance metrics gathering. Added CI job which also upload it to influx db and once we fill out 10 historical values every measurement will be checked for regression. 

scripts/benchmarks/__main__.py

@@ -53,6 +53,7 @@
 upload_bench.add_argument("--benchmark", type=BenchmarkType, help="benchmark to upload")
 
 test_bench = subparsers.add_parser('test', help="Performs entire cycle of operations from run till upload")
+test_bench.add_argument("--no-run", help="skip running benchmark", action='store_true')
 test_bench.add_argument("--benchmark", type=BenchmarkType, help="benchmark to test")
 test_bench.add_argument("--tmpfile", help="temporary location of result file", default="/tmp/bench.tmp")
 test_bench.add_argument("--input-file", help="input file with raw benchmark", default="input.json")
@@ -89,6 +90,8 @@ def select_benchmark(kind):
         return MinaBaseBenchmark()
     elif kind == BenchmarkType.zkapp:
         return ZkappLimitsBenchmark()
+    elif kind == BenchmarkType.archive:
+        return ArchiveBenchmark()
     elif kind == BenchmarkType.heap_usage:
         return HeapUsageBenchmark()
     elif kind == BenchmarkType.snark:
@@ -136,11 +139,16 @@ def select_benchmark(kind):
     bench.upload(args.infile)
 
 if args.cmd == "test":
-    output = bench.run(path=args.path)
+    if args.no_run:
+        print("Skipping running benchmark")
+        output = Path(args.input_file).read_text()
+    else:
+        output = bench.run(path=args.path)
+
     files = bench.parse(output,
-                        args.tmpfile,
-                        influxdb=True,
-                        branch=args.branch)
+            args.tmpfile,
+            influxdb=True,
+            branch=args.branch)
 
     [
         bench.compare(file, args.yellow_threshold, args.red_threshold)
@@ -151,4 +159,4 @@ def select_benchmark(kind):
 
     if args.branch in mainline_branches:
         for file in files:
-            bench.upload(file)
+            bench.upload(file)

scripts/benchmarks/lib/bench.py

@@ -160,6 +160,7 @@ class BenchmarkType(Enum):
     zkapp = 'zkapp'
     ledger_export = 'ledger-export'
     ledger_apply = 'ledger-apply'
+    archive = 'archive'
 
     def __str__(self):
         return self.value
@@ -444,6 +445,72 @@ def parse(self, content, output_filename, influxdb, branch):
 
         return [output_filename]
 
+class ArchiveBenchmark(Benchmark):
+    """
+     Concrete implementation of Benchmark for archive benchmark.
+     It requires input json file with benchmark data in format
+     {
+        "final_time":"0.4000" # In ms
+        , "preparation_steps_mean": "0.432"
+     }
+    """
+
+    name = MeasurementColumn("Name", 0)
+    time = FieldColumn("time",  1, "ms")
+    category = TagColumn("category", 2)
+    branch = TagColumn("gitbranch", 3)
+
+    def __init__(self):
+        Benchmark.__init__(self, BenchmarkType.archive)
+
+    def run(self, path=None):
+        pass
+
+    def fields(self):
+        return [
+            self.time
+        ]
+
+    def name_header(self):
+        return self.name
+
+    def branch_header(self):
+        return self.branch
+
+    def default_path(self):
+        return ""
+
+    def headers(self):
+        return [
+            ArchiveBenchmark.name, ArchiveBenchmark.time,
+            ArchiveBenchmark.category, ArchiveBenchmark.branch
+        ]
+
+    # format of input file: 
+    # [{"operation":"Zkapp_account_update.add","avg_time_ms":4.994700819672131}
+    # ,{"operation":"Zkapp_account_update_body.add","avg_time_ms":3.1188038147138974}
+    # , ...
+    # ]
+    def parse(self, content, output_filename, influxdb, branch):
+
+        operation = "operation"
+        avg_time_ms = "avg_time_ms"
+
+        data = json.loads(content)
+
+        with open(output_filename, 'w') as csvfile:
+            if influxdb:
+                csvfile.write(
+                    self.headers_to_influx(self.headers()) + "\n")
+            for item in data:
+                operation_name = item[operation]
+                avg_time = item[avg_time_ms]
+                csvwriter = csv.writer(csvfile)
+                csvwriter.writerow((operation_name, avg_time, "archive", branch))
+
+        return [output_filename]
+
+
 class ZkappLimitsBenchmark(Benchmark):
     """
      ZkappLimit benchmark has it's own output which we need to handle separately. It is similar to:

src/app/archive/lib/diff.ml

@@ -93,13 +93,10 @@ module Builder = struct
               Some (index, account) )
     in
     let accounts_accessed_time = Time.now () in
-    [%log debug]
-      "Archive data generation for $state_hash: accounts-accessed took $time ms"
-      ~metadata:
-        [ ("state_hash", Mina_base.State_hash.to_yojson state_hash)
-        ; ( "time"
-          , `Float (Time.Span.to_ms (Time.diff accounts_accessed_time start)) )
-        ] ;
+    Metrics.report_time ~logger ~label:"accounts-accessed"
+      ~extra_metadata:
+        [ ("state_hash", Mina_base.State_hash.to_yojson state_hash) ]
+      (Time.diff accounts_accessed_time start) ;
     let accounts_created =
       let account_creation_fee =
         precomputed_values.constraint_constants.account_creation_fee
@@ -125,15 +122,11 @@ module Builder = struct
           (token_id, owner) )
     in
     let account_created_time = Time.now () in
-    [%log debug]
-      "Archive data generation for $state_hash: accounts-created took $time ms"
-      ~metadata:
-        [ ("state_hash", Mina_base.State_hash.to_yojson state_hash)
-        ; ( "time"
-          , `Float
-              (Time.Span.to_ms
-                 (Time.diff account_created_time accounts_accessed_time) ) )
-        ] ;
+    Metrics.report_time ~logger ~label:"accounts-created"
+      ~extra_metadata:
+        [ ("state_hash", Mina_base.State_hash.to_yojson state_hash) ]
+      (Time.diff account_created_time accounts_accessed_time) ;
+
     Transition_frontier.Breadcrumb_added
       { block =
           With_hash.map ~f:Mina_block.read_all_proofs_from_disk block_with_hash

src/app/archive/lib/metrics.ml

@@ -1,13 +1,34 @@
 open Core_kernel
 open Async
 
-let time ~label f =
+(** [report_time ~label ?extra_metadata elapsed] logs a performance metric with the given [label] and [elapsed] time.
+  - [label]: A string describing the metric being reported.
+  - [extra_metadata]: An optional list of additional metadata key-value pairs to include in the log (default: []).
+  - [elapsed]: The time span to report, as a [Time.Span.t].
+  The log entry will include the label, the elapsed time (in human-readable format and milliseconds), and any extra metadata provided.
+*)
+let report_time ~logger ~label ?(extra_metadata = []) elapsed =
+  [%log info] "%s took %s" label
+    (Time.Span.to_string_hum elapsed)
+    ~metadata:
+      ( [ ("is_perf_metric", `Bool true)
+        ; ("label", `String label)
+        ; ("elapsed", `Float (Time.Span.to_ms elapsed))
+        ]
+      @ extra_metadata )
+
+(** [time ~label f] measures the execution time of the monadic function [f], reports the elapsed time with the given [label], and returns the result of [f]. 
+
+  @param label A string label used to identify the timing report.
+  @param f A function of type unit -> 'a Deferred.t whose execution time will be measured.
+  @return The result of [f ()], after reporting the elapsed time.
+*)
+let time ~label ~logger f =
   let start = Time.now () in
   let%map x = f () in
   let stop = Time.now () in
-  [%log' info (Logger.create ())]
-    "%s took %s" label
-    (Time.Span.to_string_hum (Time.diff stop start)) ;
+  let elapsed = Time.diff stop start in
+  report_time ~logger ~label elapsed ;
   x
 
 let default_missing_blocks_width = 2000
@@ -17,8 +38,8 @@ module Max_block_height = struct
     Caqti_request.find Caqti_type.unit Caqti_type.int
       "SELECT GREATEST(0, MAX(height)) FROM blocks"
 
-  let update (module Conn : Caqti_async.CONNECTION) metric_server =
-    time ~label:"max_block_height" (fun () ->
+  let update ~logger (module Conn : Caqti_async.CONNECTION) metric_server =
+    time ~label:"max_block_height" ~logger (fun () ->
         let open Deferred.Result.Let_syntax in
         let%map max_height = Conn.find query () in
         Mina_metrics.(
@@ -40,10 +61,10 @@ module Missing_blocks = struct
       |sql}
          missing_blocks_width )
 
-  let update ~missing_blocks_width (module Conn : Caqti_async.CONNECTION)
-      metric_server =
+  let update ~logger ~missing_blocks_width
+      (module Conn : Caqti_async.CONNECTION) metric_server =
     let open Deferred.Result.Let_syntax in
-    time ~label:"missing_blocks" (fun () ->
+    time ~label:"missing_blocks" ~logger (fun () ->
         let%map missing_blocks = Conn.find (query missing_blocks_width) () in
         Mina_metrics.(
           Gauge.set
@@ -61,9 +82,9 @@ module Unparented_blocks = struct
            WHERE parent_id IS NULL
       |sql}
 
-  let update (module Conn : Caqti_async.CONNECTION) metric_server =
+  let update ~logger (module Conn : Caqti_async.CONNECTION) metric_server =
     let open Deferred.Result.Let_syntax in
-    time ~label:"unparented_blocks" (fun () ->
+    time ~label:"unparented_blocks" ~logger (fun () ->
         let%map unparented_block_count = Conn.find query () in
         Mina_metrics.(
           Gauge.set
@@ -93,7 +114,7 @@ let update ~logger ~missing_blocks_width pool metric_server =
   Deferred.all_unit
     (List.map
        ~f:(log_error ~logger pool metric_server)
-       [ Max_block_height.update
-       ; Unparented_blocks.update
-       ; Missing_blocks.update ~missing_blocks_width
+       [ Max_block_height.update ~logger
+       ; Unparented_blocks.update ~logger
+       ; Missing_blocks.update ~logger ~missing_blocks_width
        ] )