Slow performance when listing assets in version 3.0.0

[SamyPesse]

CC @todvora

Potential solutions

Since the issue come from fs.listAllFiles, one solution could be to use node-glob when using the NodeFS instead of current recursive method.

Timing logs

info: debug: 0.0% of time spent in "call.hook.finish:before" (1 times) :
info: debug:     > Total: 1ms | Average: 1ms 
debug:     > Min: 1ms | Max: 1ms 
debug: ---------------------------
info: debug: 0.0% of time spent in "parse.listPages" (1 times) : 
debug:     > Total: 1ms | Average: 1ms 
debug:     > Min: 1ms | Max: 1ms
info: debug: --------------------------- 
debug: 0.0% of time spent in "call.hook.page:before" (1 times) : 
debug:     > Total: 2ms | Average: 2ms
info: debug:     > Min: 2ms | Max: 2ms 
debug: --------------------------- 
debug: 0.0% of time spent in "call.hook.config" (1 times) :
info: debug:     > Total: 2ms | Average: 2ms 
debug:     > Min: 2ms | Max: 2ms 
debug: ---------------------------
info: debug: 0.0% of time spent in "call.hook.finish" (1 times) : 
debug:     > Total: 3ms | Average: 3ms 
debug:     > Min: 3ms | Max: 3ms
info: debug: --------------------------- 
debug: 0.1% of time spent in "call.hook.page" (1 times) : 
debug:     > Total: 8ms | Average: 8ms
info: debug:     > Min: 8ms | Max: 8ms 
debug: --------------------------- 
debug: 0.2% of time spent in "page.generate" (1 times) :
info: debug:     > Total: 26ms | Average: 26ms 
debug:     > Min: 26ms | Max: 26ms 
debug: ---------------------------
info: debug: 0.3% of time spent in "template.render" (2 times) : 
debug:     > Total: 49ms | Average: 25ms 
debug:     > Min: 4ms | Max: 45ms
info: debug: --------------------------- 
debug: 0.4% of time spent in "call.hook.init" (1 times) : 
debug:     > Total: 58ms | Average: 58ms
info: debug:     > Min: 58ms | Max: 58ms 
debug: --------------------------- 
debug: 0.5% of time spent in "parse.book" (1 times) :
info: debug:     > Total: 70ms | Average: 70ms 
debug:     > Min: 70ms | Max: 70ms 
debug: ---------------------------
info: debug: 0.7% of time spent in "plugin.load" (7 times) : 
debug:     > Total: 105ms | Average: 15ms 
debug:     > Min: 1ms | Max: 67ms 
debug: ---------------------------
info: debug: 11.3% of time spent in "plugins.findForBook" (1 times) : 
debug:     > Total: 1.65s | Average: 1.65s 
debug:     > Min: 1.65s | Max: 1.65s
info: debug: --------------------------- 
debug: 80.2% of time spent in "parse.listAssets" (1 times) : 
debug:     > Total: 11.74s | Average: 11.74s 
debug:     > Min: 11.74s | Max: 11.74s
info: debug: --------------------------- 
debug: 918ms spent in non-mesured sections

[todvora]

Looks good in 3.0.0-pre.15. Thank you! Build times are now usually under 4 seconds in my setup.

Currently the bottleneck is plugins.findForBook with about 2 seconds and 50-60% of total time spent.

Using gitbook version 3.0.0-pre.15
7 plugins are installed
loading plugin "image-captions"...
OK
loading plugin "highlight"...
OK
loading plugin "search"...
OK
loading plugin "lunr"...
OK
loading plugin "sharing"...
OK
loading plugin "fontsettings"...
OK
loading plugin "theme-default"...
OK
found 4 pages
found 1 asset files
>> generation finished with success in 2.9s !
debug: 0.1% of time spent in "call.hook.finish:before" (1 times) :
debug:     > Total: 2ms | Average: 2ms
debug:     > Min: 2ms | Max: 2ms
debug: ---------------------------
debug: 0.1% of time spent in "parse.listAssets" (1 times) :
debug:     > Total: 3ms | Average: 3ms 
debug:     > Min: 3ms | Max: 3ms
debug: --------------------------- 
debug: 0.1% of time spent in "call.hook.config" (1 times) :
debug:     > Total: 3ms | Average: 3ms 
debug:     > Min: 3ms | Max: 3ms
debug: --------------------------- 
debug: 0.1% of time spent in "call.hook.finish" (1 times) :
debug:     > Total: 5ms | Average: 5ms 
debug:     > Min: 5ms | Max: 5ms
debug: --------------------------- 
debug: 0.3% of time spent in "parse.listPages" (1 times) :
debug:     > Total: 11ms | Average: 11ms 
debug:     > Min: 11ms | Max: 11ms
debug: --------------------------- 
debug: 0.3% of time spent in "call.hook.page:before" (4 times) :
debug:     > Total: 13ms | Average: 3ms 
debug:     > Min: 3ms | Max: 4ms
debug: --------------------------- 
debug: 1.1% of time spent in "call.hook.page" (4 times) : 
debug:     > Total: 42ms | Average: 11ms 
debug:     > Min: 6ms | Max: 23ms 
debug: ---------------------------
debug: 1.9% of time spent in "parse.book" (1 times) : 
debug:     > Total: 73ms | Average: 73ms
debug:     > Min: 73ms | Max: 73ms 
debug: ---------------------------
debug: 2.5% of time spent in "call.hook.init" (1 times) : 
debug:     > Total: 95ms | Average: 95ms
debug:     > Min: 95ms | Max: 95ms
debug: ---------------------------
debug: 2.6% of time spent in "page.generate" (4 times) :
debug:     > Total: 101ms | Average: 25ms
debug:     > Min: 18ms | Max: 42ms 
debug: ---------------------------
debug: 4.5% of time spent in "plugin.load" (7 times) :
debug:     > Total: 174ms | Average: 25ms 
debug:     > Min: 2ms | Max: 106ms 
debug: ---------------------------
debug: 5.5% of time spent in "template.render" (8 times) : 
debug:     > Total: 213ms | Average: 27ms
debug:     > Min: 1ms | Max: 64ms 
debug: ---------------------------
debug: 54.7% of time spent in "plugins.findForBook" (1 times) :
debug:     > Total: 2.11s | Average: 2.11s 
debug:     > Min: 2.11s | Max: 2.11s
debug: --------------------------- 
debug: 1.01s spent in non-mesured sections