Serial part of build

[Waldek Hebisch]

I looked a what takes time during serial part of build. More
precisly, during database bootstrap step (that is 'boo_db.input').
From top-level point of view most time goes into compilation
of Spad files (about 90%) and about 10% of time is spent in
'make-databases'. At lower level time usage of mostly spread
out into many small contibutions. Biggest single item is
'COMPILE-FILE' (23.3%), next is pretty printer (about 15%) and
EVAl. Also, significant time goes into parsing and scanning of
Spad sources (2.9% + 8.5%). Surprisingly expensive is clearing
of category caches (7%). What could be improved? We probably
could save part of time spent in 'COMPILE-FILE', say by tweaking
optimization setting or (as Qian did) loading files in interpret
mode. But trying

)lisp (proclaim '(optimize (speed 0) (safety 1) (compilation-speed 3)))

before database bootstrap made no differece.

I am affraid that bigger gain is possible only as sum of several
small improvements. For example both Lisp pretty
printing and Spad syntactic processing take much more time than
they should (on my machine pretty printer spends about 880 clocks
per output charater), but speeding them up really means new
faster implementation, so nontrivial work. Some gains may be
easy, but probably would produce only small effect, so we would
need many such improvements to have visible speedup.


Top positions (slightly abbreviated to make it clear) in profile are:

------------------------------------------------------------------------
2750 23.3 |compDefineLisplib| [986]
1 0.0 2750 23.3 COMPILE-FILE [991]
------------------------------------------------------------------------
2 0.0 (LABELS #:BODY-NAME-2161 :IN PPRINT-FILL) [108]
1405 11.9 (LABELS SB-IMPL::HANDLE-IT :IN SB-KERNEL:OUTPUT-O
BJECT) [142]
14 0.1 1852 15.7 SB-PRETTY:OUTPUT-PRETTY-OBJECT [157]
------------------------------------------------------------------------
1 0.0 |DomainSubstitutionFunction| [2232]
1 0.0 |get_database2| [134]
1 0.0 |compSPADSLAM| [1703]
1104 9.3 |eval| [96]
21 0.2 PRINT-AND-EVAL-DEFUN [1702]
1176 9.9 |npboot| [1629]
19 0.2 2322 19.6 EVAL [124]
2 0.0 SB-INT:EVAL-IN-LEXENV [881]
28 0.2 SB-KERNEL:MAKE-NULL-LEXENV [61]
2266 19.2 SB-EVAL:EVAL-IN-NATIVE-ENVIRONMENT [38]
------------------------------------------------------------------------
1176 9.9 SB-EVAL::EVAL-TAGBODY [1665]
0 0.0 1176 9.9 SB-EVAL::EVAL-RETURN-FROM [1664]
1098 9.3 |make_databases| [2968]
78 0.7 |processGlobals| [1663]
------------------------------------------------------------------------
164 1.4 |merge_info_from_nrlib1| [1769]
665 5.6 |compDefineLisplib| [986]
0 0.0 830 7.0 |clearConstructorCaches| [1885]
1 0.0 PNAME [238]
1 0.0 |clearConstructorCaches| [1885]
1 0.0 SB-IMPL::GETHASH3 [45]
828 7.0 |clearCategoryCaches| [115]
------------------------------------------------------------------------
10484 88.7 |compilerDoit| [1540]
0 0.0 10484 88.7 |spadCompile1| [1539]
2 0.0 |ncloopIncFileName| [1622]
10482 88.7 |handle_input_file| [1538]
------------------------------------------------------------------------
662 5.6 |merge_info_from_objects| [1770]
11727 99.2 |intloopInclude| [1548]
10482 88.7 |spadCompile1| [1539]
0 0.0 11727 99.2 |handle_input_file| [1538]
5 0.0 (FLET #:CLEANUP-FUN-610 :IN |handle_input_file|) [2199]
23 0.2 |sayKeyedMsg| [893]
614 5.2 |merge_info_from_nrlib1| [1769]
23 0.2 OPEN [627]
9 0.1 SB-SYS:MAKE-FD-STREAM [490]
1117 9.4 |intloopInclude0| [1547]
9937 84.0 |fakeloopInclude0| [1537]
------------------------------------------------------------------------
10470 88.5 |fakeloopInclude0| [1537]
4 0.0 10470 88.5 |fakeloopProcess| [411]
1 0.0 |incAppend| [630]
2 0.0 SB-IMPL::LIST-NREVERSE* [87]
48 0.4 |InterpExecuteSpadSystemCommand| [1545]
9402 79.5 |fakeloopProcess1| [607]
26 0.2 |processSymbol| [90]
985 8.3 |StreamNull| [139]
------------------------------------------------------------------------
9402 79.5 |fakeloopProcess| [411]
2 0.0 9402 79.5 |fakeloopProcess1| [607]
1 0.0 |finish_comment| [617]
9060 76.6 |S_process| [1588]
339 2.9 |parse_Expr| [261]
------------------------------------------------------------------------

Notes:
- 'StreamNull' above is really Spad scanner (part responsible
for turning Spad files into stream of tokens).
- 'make_databases' is called from EVAL, so it is counted in total
time taken by EVAL. One should subtract this to get time spent
in other calls to EVAL.
- 'S_process' is Spad compilation proper. 'COMPILE-FILE', and most of
other lower level calls is made during Spad compilation.

--
Waldek Hebisch

[Qian Yun]

The daase generation is not that long on a fast machine:
it's around 25 seconds with sbcl.

---- boo_db.input
)boot $SaveParseOnly := true
)read komp_all.input
)boot processGlobals()
)boot $SaveParseOnly := nil
)boot $bootStrapMode := true
)boot $bootstrapDomains := true
)boot $createLocalLibDb := false
)read komp_all.input
)boot $bootStrapMode := false
)boot $tryRecompileArguments := false
)read boot_doms.input
)boot make_databases([], false)
----

The majority time seems to be spent in "boot_doms.input".
Which compiles 314 spad files. But I think we can compile those
files in parallel if we dump a Lisp image here?

- Qian

[Waldek Hebisch]

On Thu, May 23, 2024 at 08:04:21PM +0800, Qian Yun wrote:
> The daase generation is not that long on a fast machine:
> it's around 25 seconds with sbcl.
>
> ---- boo_db.input
> )boot $SaveParseOnly := true
> )read komp_all.input
> )boot processGlobals()
> )boot $SaveParseOnly := nil
> )boot $bootStrapMode := true
> )boot $bootstrapDomains := true
> )boot $createLocalLibDb := false
> )read komp_all.input
> )boot $bootStrapMode := false
> )boot $tryRecompileArguments := false
> )read boot_doms.input
> )boot make_databases([], false)
> ----
>
> The majority time seems to be spent in "boot_doms.input".
> Which compiles 314 spad files. But I think we can compile those
> files in parallel if we dump a Lisp image here?

I am not sure. At least we world need proper dependencies. Most of
those files are categories. We compile categories because compiling
may need to load compiled categories. And compiling a category need
categories that it uses. Our list of categories to compile is sorted
so that dependencies are compiled first.

--
Waldek Hebisch

[Qian Yun]

On 5/24/24 06:32, Waldek Hebisch wrote:
>
> I am not sure. At least we world need proper dependencies. Most of
> those files are categories. We compile categories because compiling
> may need to load compiled categories. And compiling a category need
> categories that it uses. Our list of categories to compile is sorted
> so that dependencies are compiled first.
>

I was not aware that there's order in CATLIST.

Can you update this information to doc/algebra_build.txt?
Also does other parts of that file need update?

- Qian

[Waldek Hebisch]

On Fri, May 24, 2024 at 05:13:10PM +0800, Qian Yun wrote:
>
>
> On 5/24/24 06:32, Waldek Hebisch wrote:
> >
> > I am not sure. At least we world need proper dependencies. Most of
> > those files are categories. We compile categories because compiling
> > may need to load compiled categories. And compiling a category need
> > categories that it uses. Our list of categories to compile is sorted
> > so that dependencies are compiled first.
> >
>
> I was not aware that there's order in CATLIST.
>
> Can you update this information to doc/algebra_build.txt?

Well, 'doc/algebra_build.txt' clearly say that there are dependencies,
in particular there is:

: FriCAS types are represented by
: executable code and sometimes FriCAS needs to load actual compiled
: code. FriCAS needs to load categories given as arguments to 'Join',
: because 'Join' is implemented as a runtime operation. Also
: FriCAS needs to load a category given as an argument to a constructor
: if this category itself has arguments.

There is also:

: The first four stages are purely sequential.

Maybe we should add after that:

In stage 3 and 4 categories and core domains are compiled in order, so
that dependencies came before constructors needing them.

> Also does other parts of that file need update?

That really is question to potential readers. For me 'purely
sequential' means that we care order and by inference order
is chosen to satisfy dependencies. But it may help to be
more explicit here.

--
Waldek Hebisch

[Qian Yun]

I just found out that SBCL can COMPILE-FILE in parallel (threads).

I wonder if we can compile SPAD files in parallel.

A little bit of naive trying shows that we should first handle
a issue related with dynamic variable "$inclAssertions".

Then fails in "abbreviationsSpad2Cmd" because
Unsafe concurrent operations on #<HASH-TABLE :TEST EQUAL :COUNT 14
{1000543DE3}> detected.

I wonder if this is easy to solve and if there are more races ahead.

- Qian

[Waldek Hebisch]

On Mon, Oct 28, 2024 at 08:21:58PM +0800, Qian Yun wrote:
> I just found out that SBCL can COMPILE-FILE in parallel (threads).
>
> I wonder if we can compile SPAD files in parallel.
>
> A little bit of naive trying shows that we should first handle
> a issue related with dynamic variable "$inclAssertions".
>
> Then fails in "abbreviationsSpad2Cmd" because
> Unsafe concurrent operations on #<HASH-TABLE :TEST EQUAL :COUNT 14
> {1000543DE3}> detected.
>
> I wonder if this is easy to solve and if there are more races ahead.

I think doing early Spad compilation in parallel is hopeless. Early
compilation is done is serial way because we need to get information
into symbol tables. Trying to make symbol tables to work in parallel
is IMO more tricky than making them faster as serial thing. In
principle there could be some gain from parallel compilation of
generated Lisp.

--
Waldek Hebisch

[Qian Yun]

Yes, by using ":SYNCHRONIZED t" to "make-hash-table",
the hash table issue goes away.

Next is "SPAD_READER" exception. Looks like our parser code relies
heavily on global variables and stack.

I'll try to only compile Lisp files in parallel later then.

- Qian