ocamlbuild takes up to one minute to scan already done parts of Coq sources

[vicuna]

Original bug ID: 4934
Reporter: letouzey
Status: closed (set by @gasche on 2016-02-16T00:23:34Z)
Resolution: suspended
Priority: normal
Severity: minor
Version: 3.11.1
Target version: later
Category: -for ocamlbuild use https://github.com/ocaml/ocamlbuild/issues
Tags: patch
Related to: #5754 #5756
Monitored by: @gasche mehdi @ygrek @glondu "Julien Signoles"

Bug description

Hi!

I'm investigating the use of ocamlbuild for building Coq. I'd be glad to completely get rid of nasty Makefile stuff, but currently, two major issues prevent a complete switch to ocamlbuild. One is the lack of proper parallel compilation (see a forthcoming bug report). Another is that the delay needed by ocamlbuild to scan already built parts (> 1min here) prohibits using it
for interactive development (edit a file, recompile, and so on). I've already had private discussions on this topic, without clear solutions, so I turn this into a proper bug report, for the records.

Disclaimer: I clearly do not claim my myocamlbuild.ml file to be perfect, so
this inefficiency can be caused by the way it is written. Any hints are welcome...

Best regards,
Pierre Letouzey

Instructions to reproduce:

0. you'll need camlp5 installed
1. get a copy of coq development archive
   svn checkout svn://scm.gforge.inria.fr/svn/coq/trunk/
2. ./configure -local -opt
3. Launch a first build via ocamlbuild (./build is a small wrapper)
   ./build
4. Launch ./build again

Here, the first build says:
Finished, 2716 targets (0 cached) in 00:13:10.

While the second says:
Finished, 2716 targets (2716 cached) in 00:01:07.

With old-style make, the second run of make says instantly that nothing is to be done.

NB: I've tried the patch for bug #4922, unfortunately it doesn't help.
We're not recompiling too many files here, simply taking too much time
scanning cached things.

File attachments

• 0001-cache-expand_module.patch
• 0002-disable-logging-in-Solver.self.patch
• 0003-specialize-List.union.patch
• 0004-specialize-hashtbl-for-Resource.Cache.patch

[vicuna]

Comment author: @ygrek

Here are some observations.
Ocaml_utils.expand_module is pure and called too often (and generates lots of garbage) with same arguments - simple memoisation reduces the number of invocations by the factor of 100 (for coq sources) and cuts running time by 30 sec (out of 2 minutes).
Solver.self calls dprintf which doesn't print anything at default logging level, but still incurs too much overhead, commenting it out cuts another 40 seconds. (One day I hope to have type-safe camlp4 printf which doesn't parse format string at runtime..)
Another offender is generic compare_val called from various places - specializing My_std.List.union and Hashtbl in Resource.Cache casts away 8 more seconds.
Contrary to my expectation using Set(String) instead of list to detect circular deps in Solver.self didn't give speedup..

All in all - 42 seconds vs 2+ minutes. Quick'n'dirty patches attached.

BTW better names for anonymous functions and better debug-symbol info would be greatly appreciated for debugging such issues

[vicuna]

Comment author: @ygrek

Why not apply at least the first patch?

[vicuna]

Comment author: meyer

Ygrek, your patch is being considered for an inclusion - at least the first one, however it looks we have general scalability problems with ocamlbuild, and until we will know what we can do to improve it in general case, I will postpone applying it. I don't believe scanning the tree should take that long. What we can also do is to spawn several processes scanning the tree - but this will be the last thing we we will do, however.

[vicuna]

Comment author: meyer

As for the logging - we could functorize the implementation, and replace the logging functions with a dummy ones if the user requested logging. I'll look into that.

[vicuna]

Comment author: meyer

I raised #5756 for this chunk of work.

[vicuna]

Comment author: meyer

Ygrek, for your patch # 4: I think what we want to do is to get rid of lists all together, and replace them with something better (e.g: Set). Nevertheless it highlights some obvious optimisations we could do.

[vicuna]

Comment author: @ygrek

I agree that there are speed problems at different levels, and not doing unnecessary work is the best optimisation anyway :)
I doubt it is possible to fix logging with functorizing.. Maybe better wrap it oldschool way with : if loglevel X then ...

[vicuna]

Comment author: @ygrek

FTR patch #1 was included in 4.01.0
For the other patches see #219

[vicuna]

Comment author: egallego

This issue is superseded by ocaml/ocamlbuild#52

[vicuna]

Comment author: @gasche

I'm closing the ticket to migrate further discussions to the new ocamlbuild bugtracker. Note that ygrek's patches from #219 have been merged upstream.