From d805130fae9e6a9771e9d7f6afefc86193304af3 Mon Sep 17 00:00:00 2001 From: mattiasdrp Date: Tue, 26 Nov 2024 14:07:31 +0100 Subject: [PATCH 1/2] Propagate the Profiler changes to the documentation The Profiler functions now take a `(string * metadata)` pair as their first argument. This was not changed in the documentation which could slow down potential users --- docs/developer/ppx_profiler.rst | 45 +++++++++++---------- docs/developer/profiler_module.rst | 65 ++++++++++++++++++++---------- src/lib_base/profiler.mli | 20 ++++----- 3 files changed, 77 insertions(+), 53 deletions(-) diff --git a/docs/developer/ppx_profiler.rst b/docs/developer/ppx_profiler.rst index 8a53ce509e3e..cec2f8906d35 100644 --- a/docs/developer/ppx_profiler.rst +++ b/docs/developer/ppx_profiler.rst @@ -26,11 +26,11 @@ That can be used like this .. code-block:: OCaml - Profiler.aggregate_f "advertise mempool" @@ fun () -> + Profiler.aggregate_f ~verbosity:Info ("advertise mempool", []) @@ fun () -> advertise pv_shell advertisable_mempool; let* _res = - Profiler.aggregate_s "set mempool" @@ fun () -> + Profiler.aggregate_s ~verbosity:Info ("set mempool", []) @@ fun () -> set_mempool pv_shell our_mempool in ... @@ -48,13 +48,13 @@ This will allow to preprocess .. code-block:: OCaml - () [@profiler.record "merge store"] ; + () [@profiler.record {verbosity = Info} "merge store"] ; into .. code-block:: OCaml - Profiler.record "merge store" ; + Profiler.record ~verbosity:Info ("merge store", []) ; () ; It should be noted that a ``Profiler`` module has to be available and has to @@ -68,13 +68,13 @@ declare your PPX attribute with a ``profiler_module`` field: .. code-block:: OCaml - () [@profiler.record {profiler_module = My_profiler} "merge store"] ; + () [@profiler.record {verbosity = Info; profiler_module = My_profiler} "merge store"] ; This will be preprocessed into .. code-block:: OCaml - My_profiler.record "merge store" ; + My_profiler.record ~verbosity:Info ("merge store", []) ; () ; @@ -89,10 +89,10 @@ There are three types of functions in the Profiler library. These functions are (for details about them, look at the :doc:`./profiler_module` document) -- ``aggregate : ?verbosity:verbosity -> string -> unit`` -- ``mark : ?verbosity:verbosity -> string list -> unit`` -- ``record : ?verbosity:verbosity -> string -> unit`` -- ``stamp : ?verbosity:verbosity -> string -> unit`` +- ``aggregate : verbosity:verbosity -> string * metadata -> unit`` +- ``mark : verbosity:verbosity -> string list * metadata -> unit`` +- ``record : verbosity:verbosity -> string * metadata -> unit`` +- ``stamp : verbosity:verbosity -> string * metadata -> unit`` - ``stop : unit -> unit`` - ``reset_block_section: Block_hash.t -> unit`` (a utility function that calls ``stop`` and ``record`` for each new block profiled) @@ -102,7 +102,7 @@ The PPX allows to replace .. code-block:: OCaml Profiler.reset_block_section Block_repr.hash new_head; - Profiler.record "merge store"; + Profiler.record ~verbosity:Info ("merge store", []); ... with @@ -111,7 +111,7 @@ with () [@profiler.reset_block_section Block_repr.hash new_head] - [@profiler.record "merge store"] ; + [@profiler.record {verbosity = Info} "merge store"] ; ... You can also decompose it to be sure of the evaluation order: @@ -119,7 +119,7 @@ You can also decompose it to be sure of the evaluation order: .. code-block:: OCaml () [@profiler.reset_block_section Block_repr.hash new_head] ; - () [@profiler.record "merge store"] ; + () [@profiler.record {verbosity = Info} "merge store"] ; ... 2. Wrapping functions @@ -127,25 +127,25 @@ You can also decompose it to be sure of the evaluation order: These functions are: -- ``aggregate_f : ?verbosity:verbosity -> string -> (unit -> 'a) -> 'a`` -- ``aggregate_s : ?verbosity:verbosity -> string -> (unit -> 'a Lwt.t) -> 'a Lwt.t`` -- ``record_f : ?verbosity:verbosity -> string -> (unit -> 'a) -> 'a`` -- ``record_s : ?verbosity:verbosity -> string -> (unit -> 'a Lwt.t) -> 'a Lwt.t`` -- ``span_f : ?verbosity:verbosity -> string list -> (unit -> 'a) -> 'a`` -- ``span_s : ?verbosity:verbosity -> string list -> (unit -> 'a Lwt.t) -> 'a Lwt.t`` +- ``aggregate_f : verbosity:verbosity -> string * metadata -> (unit -> 'a) -> 'a`` +- ``aggregate_s : verbosity:verbosity -> string * metadata -> (unit -> 'a Lwt.t) -> 'a Lwt.t`` +- ``record_f : verbosity:verbosity -> string * metadata -> (unit -> 'a) -> 'a`` +- ``record_s : verbosity:verbosity -> string * metadata -> (unit -> 'a Lwt.t) -> 'a Lwt.t`` +- ``span_f : verbosity:verbosity -> string list * metadata -> (unit -> 'a) -> 'a`` +- ``span_s : verbosity:verbosity -> string list * metadata -> (unit -> 'a Lwt.t) -> 'a Lwt.t`` The PPX allows to replace .. code-block:: OCaml - (Profiler.record_f "read_test_line" @@ fun () -> read_test_line ()) + (Profiler.record_f ~verbosity:Info ("read_test_line", []) @@ fun () -> read_test_line ()) ... with .. code-block:: OCaml - (read_test_line () [@profiler.record_f "read_test_line"]) + (read_test_line () [@profiler.record_f {verbosity = Info} "read_test_line"]) ... 3. Custom functions @@ -214,6 +214,7 @@ The payload is made of two parts, the first one being optional: field ::= | verbosity = (Notice | Info | Debug) | profiler_module = module_ident + | metadata = <(string * string) list> args ::= | | | ident | empty @@ -230,7 +231,7 @@ will be preprocessed as .. code-block:: OCaml Profiler.aggregate_s ~verbosity:Info (g y z) @@ f x ; - Prof.span_f ~verbosity:Debug "label" @@ g x + Prof.span_f ~verbosity:Debug ("label", []) @@ g x ... Adding functionalities diff --git a/docs/developer/profiler_module.rst b/docs/developer/profiler_module.rst index 45f24e7d30a6..47000440d831 100644 --- a/docs/developer/profiler_module.rst +++ b/docs/developer/profiler_module.rst @@ -90,7 +90,24 @@ Octez already provides two ``Drivers``: These ``Drivers`` are specifically crafted to write text or JSON files in a Unix filesystem. As you can see, they expect two 'arguments', a ``string`` (where to -write) and a ``Profiler.verbosity`` (the level of detail expected from the profiler). +write) and a ``Profiler.verbosity`` (the maximum level of detail/verbosity +expected from the profiler). + +.. code-block:: OCaml + + type verbosity = Notice | Info | Debug + +For this tutorial, we will use ``verbosity = Info``, but developers are +encouraged to use their preferred option. + +To choose the verbosity of the profiler at runtime, the ``PROFILING`` +environment variable is used. It follows the same pattern as the ``TEZOS_LOG`` +environment variable (see :doc:`../user/logging`). + +Starting a node with +``PROFILING='shell_profiling->Notice;mempool_profiling->Debug'`` will set the +maximum verbosity for these two profilers and execute the rest of the profilers +with no maximal verbosity. We can now easily create an instance for a ``Driver``: @@ -138,10 +155,11 @@ code. .. code-block:: OCaml - module Read_profiler = (val Profiler.wrap read_profiler) + module Profiler = (val Profiler.wrap read_profiler) -Since ``read_profiler`` is already plugged to ``read_instance``, calling -``Read_profiler`` functions will work as expected. +Since ``Profiler`` is already plugged to ``read_instance``, calling +``Profiler`` functions will work as expected (and this allows to shadow the +``Profiler`` module). We can now start monitoring our code. We can start with a simple change: @@ -149,9 +167,14 @@ We can now start monitoring our code. We can start with a simple change: let () = Profiler.plug instance ; - (Profiler.record_f "read_test_line" @@ fun () -> read_test_line ()) ; - (Profiler.record_f "read_test_int" @@ fun () -> read_test_int ()) ; - Profiler.record_f "read_test_scanf" @@ fun () -> read_test_scanf () + (Profiler.record_f ~verbosity:Info ("read_test_line", []) @@ fun () -> read_test_line ()) ; + (Profiler.record_f ~verbosity:Info ("read_test_int", []) @@ fun () -> read_test_int ()) ; + Profiler.record_f ~verbosity:Info ("read_test_scanf", []) @@ fun () -> read_test_scanf () + +Note: the ``Profiler`` functions take a ``(id, metadata) : string * metadata`` as their +first parameter: +- ``id`` is used to create sections and represent the part being profiled by the function +- ``metadata`` is used by backends that need specific informations (like Prometheus) Looking at the result gives us: @@ -184,49 +207,49 @@ monitor our functions more precisely: aux 0 let read_test_int () = - Profiler.record_f "read_test_int" @@ fun () -> - let ic = Profiler.aggregate_f "open_in" @@ fun () -> open_in sample in + Profiler.record_f ~verbosity:Info ("read_test_int", []) @@ fun () -> + let ic = Profiler.aggregate_f ~verbosity:Info ("open_in", []) @@ fun () -> open_in sample in let max = ref 0 in try while true do - Profiler.aggregate_f "read_int" @@ fun () -> + Profiler.aggregate_f ~verbosity:Info ("read_int", []) @@ fun () -> read_int ic |> fun e -> if e > !max then max := e done with End_of_file -> - Profiler.aggregate_f "close_in" @@ fun () -> + Profiler.aggregate_f ~verbosity:Info ("close_in", []) @@ fun () -> close_in ic ; Format.eprintf "%d@." !max let read_test_line () = - Profiler.record_f "read_test_line" @@ fun () -> - let ic = Profiler.aggregate_f "open_in" @@ fun () -> open_in sample in + Profiler.record_f ~verbosity:Info ("read_test_line", []) @@ fun () -> + let ic = Profiler.aggregate_f ~verbosity:Info ("open_in", []) @@ fun () -> open_in sample in let max = ref 0 in try while true do - Profiler.span_f ["input_line"] @@ fun () -> + Profiler.span_f ~verbosity:Info (["input_line"], []) @@ fun () -> input_line ic |> String.split_on_char ' ' |> List.iter (fun e -> let e = int_of_string e in if e > !max then max := e) done with End_of_file -> - Profiler.aggregate_f "close_in" @@ fun () -> + Profiler.aggregate_f ~verbosity:Info ("close_in", []) @@ fun () -> close_in ic ; Format.eprintf "%d@." !max let read_test_scanf () = - Profiler.record_f "read_test_scanf" @@ fun () -> + Profiler.record_f ~verbosity:Info ("read_test_scanf", []) @@ fun () -> let ic = - Profiler.aggregate_f "open_in" @@ fun () -> Scanf.Scanning.open_in sample + Profiler.aggregate_f ~verbosity:Info ("open_in", []) @@ fun () -> Scanf.Scanning.open_in sample in let max = ref 0 in try while true do - Profiler.mark ["Scanf.bscanf"] ; + Profiler.mark ~verbosity:Info (["Scanf.bscanf"], []) ; Scanf.bscanf ic "%d " (fun i -> i) |> fun e -> if e > !max then max := e done with End_of_file -> - Profiler.aggregate_f "close_in" @@ fun () -> + Profiler.aggregate_f ~verbosity:Info ("close_in", []) @@ fun () -> Scanf.Scanning.close_in ic ; Format.eprintf "%d@." !max @@ -260,14 +283,14 @@ The execution time of ``read_int`` seems off. Replacing the following lines: .. code-block:: OCaml - Profiler.aggregate_f "read_int" @@ fun () -> + Profiler.aggregate_f ~verbosity:Info ("read_int", []) @@ fun () -> read_int ic |> fun e -> if e > !max then max := e By: .. code-block:: OCaml - Profiler.mark ["read_int"] ; + Profiler.mark ~verbosity:Info (["read_int"], []) ; read_int ic |> fun e -> if e > !max then max := e Gives a completely different result: diff --git a/src/lib_base/profiler.mli b/src/lib_base/profiler.mli index e7cf0f739cef..478f99cd5580 100644 --- a/src/lib_base/profiler.mli +++ b/src/lib_base/profiler.mli @@ -238,9 +238,9 @@ val span : profiler -> verbosity -> span -> ids -> unit (** Include a report in the current sequence. *) val inc : profiler -> report -> unit -(** [record_f profiler ?verbosity label f] will call: +(** [record_f profiler verbosity label f] will call: {[ - record profiler ?verbosity name; + record profiler verbosity name; f (); stop (); ]} *) @@ -249,9 +249,9 @@ val record_f : profiler -> verbosity -> id -> (unit -> 'a) -> 'a (** Same as {!record_f} but for Lwt function *) val record_s : profiler -> verbosity -> id -> (unit -> 'a Lwt.t) -> 'a Lwt.t -(** [aggregate_f profiler ?verbosity label f] will call: +(** [aggregate_f profiler verbosity label f] will call: {[ - aggregate profiler ?verbosity name; + aggregate profiler verbosity name; f (); stop (); ]} *) @@ -260,7 +260,7 @@ val aggregate_f : profiler -> verbosity -> id -> (unit -> 'a) -> 'a (** Same as {!aggregate_f} but for Lwt functions *) val aggregate_s : profiler -> verbosity -> id -> (unit -> 'a Lwt.t) -> 'a Lwt.t -(** [span_f profiler ?verbosity label_list f] will compute [span] but +(** [span_f profiler verbosity label_list f] will compute [span] but specifically around [f] *) val span_f : profiler -> verbosity -> ids -> (unit -> 'a) -> 'a @@ -324,9 +324,9 @@ module type GLOBAL_PROFILER = sig (** Include a report in the current sequence. *) val inc : report -> unit - (** [record_f ?verbosity label f] will call: + (** [record_f verbosity label f] will call: {[ - record ?verbosity name; + record verbosity name; f (); stop (); ]} *) @@ -335,9 +335,9 @@ module type GLOBAL_PROFILER = sig (** Same as {!record_f} but for Lwt function *) val record_s : verbosity -> id -> (unit -> 'a Lwt.t) -> 'a Lwt.t - (** [aggregate_f ?verbosity label f] will call: + (** [aggregate_f verbosity label f] will call: {[ - aggregate ?verbosity name; + aggregate verbosity name; f (); stop (); ]} *) @@ -346,7 +346,7 @@ module type GLOBAL_PROFILER = sig (** Same as {!aggregate_f} but for Lwt functions *) val aggregate_s : verbosity -> id -> (unit -> 'a Lwt.t) -> 'a Lwt.t - (** [span_f ?verbosity label_list f] will compute [span] but specifically + (** [span_f verbosity label_list f] will compute [span] but specifically around [f] *) val span_f : verbosity -> ids -> (unit -> 'a) -> 'a -- GitLab From bbf7cd923bd220b4f25052b0d28866514b321c67 Mon Sep 17 00:00:00 2001 From: mattiasdrp Date: Tue, 26 Nov 2024 16:36:56 +0100 Subject: [PATCH 2/2] Use Read_profiler everywhere in the profiler documentation This will remove the confusion between `Profiler`, the module defined in lib_base and `Read_profiler`, the wrapped module around `read_profiler` --- docs/developer/ppx_profiler.rst | 10 ++--- docs/developer/profiler_module.rst | 64 +++++++++++++++--------------- 2 files changed, 35 insertions(+), 39 deletions(-) diff --git a/docs/developer/ppx_profiler.rst b/docs/developer/ppx_profiler.rst index cec2f8906d35..572841b8adeb 100644 --- a/docs/developer/ppx_profiler.rst +++ b/docs/developer/ppx_profiler.rst @@ -64,7 +64,7 @@ can be obtained with ``module Profiler = (val Profiler.wrap my_profiler)``. Of course you can create any module with this signature but in case you didn't name it ``Profiler`` (let's say you name it ``My_profiler``) you'll have to -declare your PPX attribute with a ``profiler_module`` field: +declare your PPX attributes with a ``profiler_module`` field: .. code-block:: OCaml @@ -94,14 +94,12 @@ document) - ``record : verbosity:verbosity -> string * metadata -> unit`` - ``stamp : verbosity:verbosity -> string * metadata -> unit`` - ``stop : unit -> unit`` -- ``reset_block_section: Block_hash.t -> unit`` (a utility function that calls - ``stop`` and ``record`` for each new block profiled) The PPX allows to replace .. code-block:: OCaml - Profiler.reset_block_section Block_repr.hash new_head; + Profiler.stop (); Profiler.record ~verbosity:Info ("merge store", []); ... @@ -110,7 +108,7 @@ with .. code-block:: OCaml () - [@profiler.reset_block_section Block_repr.hash new_head] + [@profiler.stop] [@profiler.record {verbosity = Info} "merge store"] ; ... @@ -118,7 +116,7 @@ You can also decompose it to be sure of the evaluation order: .. code-block:: OCaml - () [@profiler.reset_block_section Block_repr.hash new_head] ; + () [@profiler.stop] ; () [@profiler.record {verbosity = Info} "merge store"] ; ... diff --git a/docs/developer/profiler_module.rst b/docs/developer/profiler_module.rst index 47000440d831..4e217d4545fa 100644 --- a/docs/developer/profiler_module.rst +++ b/docs/developer/profiler_module.rst @@ -75,7 +75,7 @@ anything useful for now. Why is that? Because you need to attach it to a A ``backend`` is defined in two steps: -- Select a ``Driver`` (like "this driver writes text files in a unix +- Select a ``Driver`` (like "this driver writes text files in an unix filesystem") - Define a specific ``instance`` of a ``Driver`` (like "this driver will write in this file with this level of detail") @@ -84,11 +84,11 @@ Octez already provides two ``Drivers``: .. code-block:: OCaml - val auto_write_as_txt_to_file + val auto_write_as_txt_to_file : (string * Profiler.verbosity) Profiler.driver - val auto_write_as_json_to_file + val auto_write_as_json_to_file : (string * Profiler.verbosity) Profiler.driver -These ``Drivers`` are specifically crafted to write text or JSON files in a Unix +These ``Drivers`` are specifically crafted to write text or JSON files in an Unix filesystem. As you can see, they expect two 'arguments', a ``string`` (where to write) and a ``Profiler.verbosity`` (the maximum level of detail/verbosity expected from the profiler). @@ -139,7 +139,7 @@ different files or with different format). Since it would be a little bit annoying to call each functions by giving it ``read_profiler`` as a parameter, the ``Profiler`` module offers a convenient -function that creates a module allowing to call all the ``profiler`` functions +function that creates a module allowing to call all the ``read_profiler`` functions without providing it: .. code-block:: OCaml @@ -155,23 +155,22 @@ code. .. code-block:: OCaml - module Profiler = (val Profiler.wrap read_profiler) + module Read_profiler = (val Profiler.wrap read_profiler) -Since ``Profiler`` is already plugged to ``read_instance``, calling -``Profiler`` functions will work as expected (and this allows to shadow the -``Profiler`` module). +Since ``Read_profiler`` is already plugged to ``read_instance``, calling +``Read_profiler`` functions will work as expected. We can now start monitoring our code. We can start with a simple change: .. code-block:: OCaml let () = - Profiler.plug instance ; - (Profiler.record_f ~verbosity:Info ("read_test_line", []) @@ fun () -> read_test_line ()) ; - (Profiler.record_f ~verbosity:Info ("read_test_int", []) @@ fun () -> read_test_int ()) ; - Profiler.record_f ~verbosity:Info ("read_test_scanf", []) @@ fun () -> read_test_scanf () + Read_profiler.plug instance ; + (Read_profiler.record_f ~verbosity:Info ("read_test_line", []) @@ fun () -> read_test_line ()) ; + (Read_profiler.record_f ~verbosity:Info ("read_test_int", []) @@ fun () -> read_test_int ()) ; + Read_profiler.record_f ~verbosity:Info ("read_test_scanf", []) @@ fun () -> read_test_scanf () -Note: the ``Profiler`` functions take a ``(id, metadata) : string * metadata`` as their +Note: the ``Read_profiler`` functions take a ``(id, metadata) : string * metadata`` as their first parameter: - ``id`` is used to create sections and represent the part being profiled by the function - ``metadata`` is used by backends that need specific informations (like Prometheus) @@ -189,13 +188,12 @@ monitor our functions more precisely: .. code-block:: OCaml - let profiler = Profiler.unplugged () + let profiler = Read_profiler.unplugged () - module Profiler = (val Profiler.wrap profiler) + module Read_profiler = (val Profiler.wrap profiler) let instance = - Tezos_base.Profiler.instance - Tezos_base_unix.Simple_profiler.auto_write_as_txt_to_file + Profiler.instance Tezos_base_unix.Simple_profiler.auto_write_as_txt_to_file ("/tmp/test_profiler.txt", Profiler.Info) let read_int ic = @@ -207,54 +205,54 @@ monitor our functions more precisely: aux 0 let read_test_int () = - Profiler.record_f ~verbosity:Info ("read_test_int", []) @@ fun () -> - let ic = Profiler.aggregate_f ~verbosity:Info ("open_in", []) @@ fun () -> open_in sample in + Read_profiler.record_f ~verbosity:Info ("read_test_int", []) @@ fun () -> + let ic = Read_profiler.aggregate_f ~verbosity:Info ("open_in", []) @@ fun () -> open_in sample in let max = ref 0 in try while true do - Profiler.aggregate_f ~verbosity:Info ("read_int", []) @@ fun () -> + Read_profiler.aggregate_f ~verbosity:Info ("read_int", []) @@ fun () -> read_int ic |> fun e -> if e > !max then max := e done with End_of_file -> - Profiler.aggregate_f ~verbosity:Info ("close_in", []) @@ fun () -> + Read_profiler.aggregate_f ~verbosity:Info ("close_in", []) @@ fun () -> close_in ic ; Format.eprintf "%d@." !max let read_test_line () = - Profiler.record_f ~verbosity:Info ("read_test_line", []) @@ fun () -> - let ic = Profiler.aggregate_f ~verbosity:Info ("open_in", []) @@ fun () -> open_in sample in + Read_profiler.record_f ~verbosity:Info ("read_test_line", []) @@ fun () -> + let ic = Read_profiler.aggregate_f ~verbosity:Info ("open_in", []) @@ fun () -> open_in sample in let max = ref 0 in try while true do - Profiler.span_f ~verbosity:Info (["input_line"], []) @@ fun () -> + Read_profiler.span_f ~verbosity:Info (["input_line"], []) @@ fun () -> input_line ic |> String.split_on_char ' ' |> List.iter (fun e -> let e = int_of_string e in if e > !max then max := e) done with End_of_file -> - Profiler.aggregate_f ~verbosity:Info ("close_in", []) @@ fun () -> + Read_profiler.aggregate_f ~verbosity:Info ("close_in", []) @@ fun () -> close_in ic ; Format.eprintf "%d@." !max let read_test_scanf () = - Profiler.record_f ~verbosity:Info ("read_test_scanf", []) @@ fun () -> + Read_profiler.record_f ~verbosity:Info ("read_test_scanf", []) @@ fun () -> let ic = - Profiler.aggregate_f ~verbosity:Info ("open_in", []) @@ fun () -> Scanf.Scanning.open_in sample + Read_profiler.aggregate_f ~verbosity:Info ("open_in", []) @@ fun () -> Scanf.Scanning.open_in sample in let max = ref 0 in try while true do - Profiler.mark ~verbosity:Info (["Scanf.bscanf"], []) ; + Read_profiler.mark ~verbosity:Info (["Scanf.bscanf"], []) ; Scanf.bscanf ic "%d " (fun i -> i) |> fun e -> if e > !max then max := e done with End_of_file -> - Profiler.aggregate_f ~verbosity:Info ("close_in", []) @@ fun () -> + Read_profiler.aggregate_f ~verbosity:Info ("close_in", []) @@ fun () -> Scanf.Scanning.close_in ic ; Format.eprintf "%d@." !max let () = - Profiler.plug instance ; + Read_profiler.plug instance ; read_test_line () ; read_test_int () ; read_test_scanf () @@ -283,14 +281,14 @@ The execution time of ``read_int`` seems off. Replacing the following lines: .. code-block:: OCaml - Profiler.aggregate_f ~verbosity:Info ("read_int", []) @@ fun () -> + Read_profiler.aggregate_f ~verbosity:Info ("read_int", []) @@ fun () -> read_int ic |> fun e -> if e > !max then max := e By: .. code-block:: OCaml - Profiler.mark ~verbosity:Info (["read_int"], []) ; + Read_profiler.mark ~verbosity:Info (["read_int"], []) ; read_int ic |> fun e -> if e > !max then max := e Gives a completely different result: -- GitLab