[racket-dev] Why is current-module-name-resolver taking so much time?
I decided to look at why 'make' with a fully-built install takes a
long time, and got a surprising result. First, the 'link-all.rkt'
script takes about 17 seconds on my machine, almost all of it in
`pkg-install`. I then profiled this, and got the surprising result
that the majority of the time is spent resolving module names:
----------------------------------------------------------------------------
[traversing imports] [68] 0.3%
standard-module-name-resolver [49] 0.3%
temp37 [43] 0.9%
run [5] 3.9%
??? [29] 20.2%
parse-loop88 [36] 29.1%
for-loop [21] 45.2%
[49] 11872(63.2%) 6006(32.0%) standard-module-name-resolver (unknown source)
[traversing imports] [51] 31.9%
find-col-file [52] 3.5%
show-collection-err [54] 2.0%
??? [55] 1.8%
[traversing imports] [56] 1.1%
??? [57] 1.0%
[traversing imports] [53] 0.9%
[traversing imports] [58] 0.8%
??? [59] 0.7%
??? [60] 0.5%
split-relative-string [61] 0.5%
??? [63] 0.5%
lang:read-syntax [62] 0.5%
go [64] 0.5%
standard-module-name-resolver [49] 0.3%
----------------------------------------------------------------------------
If you're unused to reading `profile` output, it says that 63.2% of
the time is spent in `standard-module-name-resolver`, with about half
that in the function itself, and half in the functions it calls in
turn.
I've never seen a profile where this turned up so high, and I'm trying
to figure out if there's some way it can be made faster. The only
call to (current-module-name-resolver) in the pkg system is on line
1333 of pkg/lib.rkt, which according to the profiler is responsible
for fewer than half of this time.
Sam