[performance] Zero-build regression 3.11 - 3.14

[ejgallego]

Hi folks,

I'm forwarding this perf regression from Coq users, as it seems interesting.

The relevant bit seems this zero-build data:

dune 3.14.0:  5.9s
dune 3.11.1:  3.3s
make 4.3:     0.6s 

That's almost 2 seconds so worth having a look IMHO.

Note that we identified a much worse performance regression while investigating this issue, see #10116

[rgrinberg]

Do you want put up some perf reports for 3.11 and 3.14? That would help triage the issue.

[ejgallego]

Indeed it seems that the perf report is giving us some clues:

3.14.0:

+   10,54%  dune        dune.exe              [.] Dune_re.Color_map.flatten_386
+    8,76%  dune        dune.exe              [.] do_some_marking
+    6,66%  dune        dune.exe              [.] Stdune.String.parse_word_752
+    6,61%  dune        dune.exe              [.] Dune_re.Core.loop_1014
+    4,03%  dune        dune.exe              [.] Stdune.String_split.loop_441
+    3,56%  dune        dune.exe              [.] caml_alloc_string
+    3,55%  dune        dune.exe              [.] caml_page_table_lookup
+    2,73%  dune        dune.exe              [.] Stdune.Path.component_436
+    2,23%  dune        dune.exe              [.] caml_oldify_one
+    2,21%  dune        libc.so.6             [.] __memmove_avx_unaligned_erms
+    2,04%  dune        dune.exe              [.] sweep_slice
+    1,90%  dune        dune.exe              [.] Dune_re.Automata.delta_1_1703
+    1,63%  dune        dune.exe              [.] Stdlib.^_141
+    1,57%  dune        dune.exe              [.] Stdlib.Bytes.sub_302
+    1,50%  dune        dune.exe              [.] caml_string_compare
+    1,44%  dune        dune.exe              [.] Stdlib.Char.chr_269
+    1,23%  dune        dune.exe              [.] bf_allocate
+    1,14%  dune        dune.exe              [.] bf_merge_block
+    1,14%  dune        dune.exe              [.] caml_make_vect
+    1,05%  dune        dune.exe              [.] Stdune.String.fun_2443
+    1,02%  dune        dune.exe              [.] Stdlib.String.index_rec_opt_483
+    0,94%  dune        dune.exe              [.] caml_blit_string
+    0,93%  dune        libc.so.6             [.] __memcmp_avx2_movbe
+    0,85%  dune        dune.exe              [.] caml_next_frame_descriptor
+    0,80%  dune        dune.exe              [.] Dune_re.Automata.delta_seq_1705
+    0,75%  dune        dune.exe              [.] caml_c_call
+    0,71%  dune        dune.exe              [.] Stdune.Path.compare_5759
+    0,70%  dune        dune.exe              [.] caml_alloc_shr_for_minor_gc
+    0,69%  dune        dune.exe              [.] Stdune.Path.loop_696
+    0,67%  dune        dune.exe              [.] Dune_re.Automata.remove_duplicates_1660
+    0,67%  dune        dune.exe              [.] Dune_re.Core.translate_1809
+    0,66%  dune        dune.exe              [.] caml_apply2
+    0,65%  dune        dune.exe              [.] caml_oldify_mopup
+    0,64%  dune        dune.exe              [.] Stdune.String.skip_blanks_751
+    0,63%  dune        dune.exe              [.] do_compare_val
+    0,57%  dune        dune.exe              [.] Dune_re.Automata.set_idx_1684
+    0,55%  dune        dune.exe              [.] caml_hash
+    0,55%  dune        dune.exe              [.] Dune_re.Automata.first_1177
+    0,54%  dune        dune.exe              [.] Dune_re.Cset.mem_330
+    0,53%  dune        dune.exe              [.] Stdlib.List.find_682
+    0,51%  dune        dune.exe              [.] Stdlib.List.rev_append_308

3.11.0:


+   13,55%  dune        dune.exe              [.] do_some_marking
    11,27%  dune        dune.exe              [.] Stdune.String.parse_word_749
     7,22%  dune        dune.exe              [.] Stdune.String_split.loop_439
+    5,84%  dune        dune.exe              [.] caml_alloc_string
+    4,75%  dune        dune.exe              [.] caml_page_table_lookup
+    4,16%  dune        dune.exe              [.] Stdune.Path.component_434
+    3,98%  dune        dune.exe              [.] caml_oldify_one
+    3,64%  dune        dune.exe              [.] sweep_slice
+    3,45%  dune        dune.exe              [.] Stdlib.^_141
+    2,66%  dune        libc.so.6             [.] __memmove_avx_unaligned_erms
+    2,40%  dune        dune.exe              [.] caml_string_compare
+    2,36%  dune        dune.exe              [.] Stdlib.Bytes.sub_302
+    2,11%  dune        dune.exe              [.] bf_allocate
     2,01%  dune        dune.exe              [.] Stdune.String.fun_2368
+    1,93%  dune        dune.exe              [.] bf_merge_block
+    1,84%  dune        libc.so.6             [.] __memcmp_avx2_movbe
     1,73%  dune        dune.exe              [.] Stdlib.String.index_rec_opt_483
+    1,64%  dune        dune.exe              [.] caml_blit_string
+    1,30%  dune        dune.exe              [.] caml_alloc_shr_for_minor_gc
     1,14%  dune        dune.exe              [.] Stdune.String.skip_blanks_748
+    1,13%  dune        dune.exe              [.] caml_oldify_mopup
+    1,12%  dune        dune.exe              [.] Stdune.Path.loop_690
+    1,06%  dune        dune.exe              [.] caml_c_call
     1,02%  dune        dune.exe              [.] Stdune.Path.compare_5616
+    0,79%  dune        dune.exe              [.] Stdlib.Map.bal_398
+    0,75%  dune        dune.exe              [.] caml_apply2
+    0,73%  dune        dune.exe              [.] Stdlib.Map.add_428
+    0,66%  dune        dune.exe              [.] Stdlib.List.rev_append_308
+    0,64%  dune        dune.exe              [.] Stdlib.Map.find_opt_512
     0,62%  dune        dune.exe              [.] caml_blit_bytes
+    0,57%  dune        dune.exe              [.] bf_split
     0,57%  dune        dune.exe              [.] caml_create_bytes
     0,52%  dune        dune.exe              [.] memmove@plt

[ejgallego]

I don't know enough perf as to fully figure out what is going on, but a possibility is that we are stuck here in the parsing of the coqdep file?

$ wc _build/default/theories/.HoTT.theory.d 
  1641  16397 435761 _build/default/theories/.HoTT.theory.d

Code in question is here

dune/src/dune_rules/coq/coq_rules.ml

Lines 521 to 559 in b5a4f6a

	(* Handle the case where the path contains ":" and coqdep escapes this
	as "\:" causing Dune to misinterpret the path. We revert
	the escaping, which allows dune to work on Windows.
	Note that coqdep escapes a few more things, including spaces, $, #,
	[], ?, %, homedir... How to handle that seems tricky.
	*)
	let unescape_coqdep string = Re.replace_string (Re.compile (Re.str "\\:")) ~by:":" string
	let parse_line ~dir line =
	match String.lsplit2 line ~on:':' with
	| None -> coqdep_invalid "split" line
	| Some (basename, deps) ->
	(* This should always have a file, but let's handle the error
	properly *)
	let target =
	match String.extract_blank_separated_words basename with
	| [] -> coqdep_invalid "target" line
	| vo :: _ -> vo
	in
	(* let depname, ext = Filename.split_extension ff in *)
	let target = Path.relative (Path.build dir) target in
	(* EJGA: XXX using `String.extract_blank_separated_words` works
	for OCaml, but not for Coq as we don't use `-modules` *)
	let deps = unescape_coqdep deps |> String.extract_blank_separated_words in
	(* Add prelude deps for when stdlib is in scope and we are not actually
	compiling the prelude *)
	let deps = List.map ~f:(Path.relative (Path.build dir)) deps in
	target, deps
	;;
	let get_dep_map ~dir ~wrapper_name : Path.t list Dep_map.t Action_builder.t =
	let file = dep_theory_file ~dir ~wrapper_name in
	let open Action_builder.O in
	let f = parse_line ~dir in
	Action_builder.lines_of (Path.build file)
	>>| fun lines ->
	List.map ~f lines
	|> Dep_map.of_list

[ejgallego]

So likely a side effect of #9231 Trivially sharing the regex compilation improves stuff a lot (see #10115 )

Due to #9306 we need to rewrite this parsing function anyways, so that could be a good opportunity to see what the speedups are.

[ejgallego]

Indeed, after memoizing the map construction, the zero build time goes from 5 sec to 0.3 , will submit a PR shortly.