Why is Hugo slow the first time I run it every day?

Each day, when I run hugo for the first time, it takes 10 to 15 seconds to finish. If I run it again, it takes milliseconds.

Is it slow the first time because it’s comparing 250 Mb of media, byte by byte? Why is it fast the second time?

This is not my experience, so you have to provide more context / a test project to give someone a remote chance of coming up with a good answer.

Taking a wild stab: Anti virus scan?

Thanks for the answer. I don’t have an antivirus. I run it on a 8 core laptop with SSD.

If I make a 300 Mb zip, will someone download it and test it? What’s the best way to share such big file?

Dropbox is one way.

Which version are you running with?

Ah! I see 0.13 is out! I will try it and report back.

This is the version: Hugo Static Site Generator v0.13 BuildDate: 2015-02-28T01:55:23+01:00

The first time I run it it takes 30 seconds (I used a stopwatch) and I get this output:

0 of 2 drafts rendered
0 future content
304 pages created
0 paginator pages created
285 tags created
14 categories created
28 places created
4 langs created
2 menu created
in 617 ms

The second and following times it takes less than 1 second.

Which files and folders should I share? config.toml, content/, layouts/ and static/ ?

Share all of it.

http://hamoid.com/blog.7z

0 of 2 drafts rendered
0 future content 
304 pages created
0 paginator pages created
285 tags created
14 categories created
28 places created
4 langs created
2 menu created
in 380 ms
1.11u 0.37s 0.80r 23148kB hugo

I have only run it once … but it was my first … 0.8 is “real time” from the time command.

Is there anything I can do to debug why it takes longer for me? To find out what it is actually doing during those 30 seconds?

What OS do you run on?

Arch Linux 64 bits

strace should give you a hint.

Dang. Can’t extract 7zip on this Mac.

The output of strace is 64Mb and half million lines :slight_smile: What should I look at?

Hard to say – in your case I would look for what it doesn’t do for 30 seconds. There should be some obious waiting between some syscalls… But now I’m guessing.

strace -c -o first.log

% time     seconds  usecs/call     calls    errors syscall
------ ----------- ----------- --------- --------- ----------------
 94.08    0.082186           0    551439           read
  3.87    0.003382           1      4967       402 futex
  1.98    0.001728          32        54           getdents64
  0.04    0.000034           0      3554         4 stat
  0.02    0.000019           0      1250           open
  0.01    0.000009           0       596         1 lstat
  0.00    0.000000           0       106           write
  0.00    0.000000           0      1254           close
  0.00    0.000000           0         9           fstat
  0.00    0.000000           0         9           mmap
  0.00    0.000000           0         1           munmap
  0.00    0.000000           0        58           rt_sigaction
  0.00    0.000000           0        15           rt_sigprocmask
  0.00    0.000000           0        78           sched_yield
  0.00    0.000000           0         3           socket
  0.00    0.000000           0         2           bind
  0.00    0.000000           0         2           setsockopt
  0.00    0.000000           0         7           clone
  0.00    0.000000           0         1           execve
  0.00    0.000000           0         1           mkdir
  0.00    0.000000           0         1           sigaltstack
  0.00    0.000000           0         1           arch_prctl
  0.00    0.000000           0         1           sched_getaffinity
------ ----------- ----------- --------- --------- ----------------
100.00    0.087358                563409       407 total


strace -c -o second.log

% time     seconds  usecs/call     calls    errors syscall
------ ----------- ----------- --------- --------- ----------------
 91.40    0.002847           0    552066           read
  7.87    0.000245           0      3968       263 futex
  0.51    0.000016           0      3537         2 stat
  0.22    0.000007           0      1559           close
  0.00    0.000000           0        78           write
  0.00    0.000000           0      1557           open
  0.00    0.000000           0       323           fstat
  0.00    0.000000           0       921         3 lstat
  0.00    0.000000           0        13           mmap
  0.00    0.000000           0         1           munmap
  0.00    0.000000           0        58           rt_sigaction
  0.00    0.000000           0        15           rt_sigprocmask
  0.00    0.000000           0        75           sched_yield
  0.00    0.000000           0         3           socket
  0.00    0.000000           0         2           bind
  0.00    0.000000           0         2           setsockopt
  0.00    0.000000           0         7           clone
  0.00    0.000000           0         1           execve
  0.00    0.000000           0         1           sigaltstack
  0.00    0.000000           0         1           arch_prctl
  0.00    0.000000           0         1           sched_getaffinity
  0.00    0.000000           0        75           getdents64
------ ----------- ----------- --------- --------- ----------------
100.00    0.003115                564264       268 total

I don’t know how to interpret these. The first run did take about half minute, but the output seems to indicate 0.08 seconds. The second run was definitely faster, and it shows 0.003 seconds. What do these numbers mean?

Sorry, I used 7z because the file size is half. If I remember right 7z notices when files are duplicated, but zip doesn’t.

What drive do you have on this machine?

A 256 Gb SSD with FDE.