Subject: bug#24937: "deleting unused links" GC phase is too slow

From: Ricardo Wurmus <[email-masked]>
Date: Thu, 16 Apr 2020 16:27:27 +0200

Here are more benchmarks on one of the build nodes.  It doesn’t nearly
have as many used inodes as ci.guix.gnu.org, but I could fill it up if
necessary.

  root@hydra-guix-127 ~# df -i /gnu/
  Filesystem       Inodes   IUsed    IFree IUse% Mounted on
  /dev/sda3      28950528 2796829 26153699   10% /

  root@hydra-guix-127 ~# ls -1 /gnu/store/.links | wc -l
  2017395

I tested all three modes with statx and with lstat.  The
links-traversal-statx.c is attached below.

* mode 1 + statx

--8<---------------cut here---------------start------------->8---
root@hydra-guix-127 ~ [env]# gcc -Wall -std=c99 links-traversal-statx.c -DMODE=1 -D_GNU_SOURCE=1 -o links-traversal
links-traversal-statx.c:53:8: warning: �stat_entries� defined but not used [-Wunused-function]
   53 |   void stat_entries (void)
      |        ^~~~~~~~~~~~
root@hydra-guix-127 ~ [env]# echo 3 > /proc/sys/vm/drop_caches
root@hydra-guix-127 ~ [env]# time ./links-traversal 
2017397 dir_entries, 9 seconds (including stat)

real    0m9.176s
user    0m0.801s
sys     0m4.236s
root@hydra-guix-127 ~ [env]# time ./links-traversal 
2017397 dir_entries, 4 seconds (including stat)

real    0m3.556s
user    0m0.708s
sys     0m2.848s
root@hydra-guix-127 ~ [env]# time ./links-traversal 
2017397 dir_entries, 4 seconds (including stat)

real    0m3.553s
user    0m0.599s
sys     0m2.954s
root@hydra-guix-127 ~ [env]# 
--8<---------------cut here---------------end--------------->8---

* mode 2 + statx

--8<---------------cut here---------------start------------->8---
root@hydra-guix-127 ~ [env]# gcc -Wall -std=c99 links-traversal-statx.c -DMODE=2 -D_GNU_SOURCE=1 -o links-traversal
root@hydra-guix-127 ~ [env]# echo 3 > /proc/sys/vm/drop_caches
root@hydra-guix-127 ~ [env]# time ./links-traversal 
17377 dir_entries, 10 seconds (including stat)

real    0m9.598s
user    0m1.210s
sys     0m4.257s
root@hydra-guix-127 ~ [env]# time ./links-traversal 
17377 dir_entries, 4 seconds (including stat)

real    0m4.094s
user    0m0.988s
sys     0m3.107s
root@hydra-guix-127 ~ [env]# time ./links-traversal 
17377 dir_entries, 4 seconds (including stat)

real    0m4.095s
user    0m0.933s
sys     0m3.162s
root@hydra-guix-127 ~ [env]# 
--8<---------------cut here---------------end--------------->8---

* mode 3 + statx

--8<---------------cut here---------------start------------->8---
root@hydra-guix-127 ~ [env]# gcc -Wall -std=c99 links-traversal-statx.c -DMODE=3 -D_GNU_SOURCE=1 -o links-traversal^C
root@hydra-guix-127 ~ [env]# echo 3 > /proc/sys/vm/drop_caches
root@hydra-guix-127 ~ [env]# time ./links-traversal 
2017397 dir_entries, 7 seconds
stat took 3 seconds

real    0m9.992s
user    0m1.411s
sys     0m4.221s
root@hydra-guix-127 ~ [env]# time ./links-traversal 
2017397 dir_entries, 1 seconds
stat took 2 seconds

real    0m4.265s
user    0m1.120s
sys     0m3.145s
root@hydra-guix-127 ~ [env]# time ./links-traversal 
2017397 dir_entries, 2 seconds
stat took 2 seconds

real    0m4.267s
user    0m1.072s
sys     0m3.195s
root@hydra-guix-127 ~ [env]# 
--8<---------------cut here---------------end--------------->8---

Now with just lstat:

* mode 1 + lstat

--8<---------------cut here---------------start------------->8---
root@hydra-guix-127 ~ [env]# gcc -Wall -std=c99 links-traversal.c -DMODE=1 -D_GNU_SOURCE=1 -o links-traversal
links-traversal.c:49:8: warning: �stat_entries� defined but not used [-Wunused-function]
   49 |   void stat_entries (void)
      |        ^~~~~~~~~~~~
root@hydra-guix-127 ~ [env]# echo 3 > /proc/sys/vm/drop_caches
root@hydra-guix-127 ~ [env]# time ./links-traversal 
2017397 dir_entries, 9 seconds (including stat)

real    0m9.303s
user    0m0.748s
sys     0m4.397s
root@hydra-guix-127 ~ [env]# time ./links-traversal 
2017397 dir_entries, 4 seconds (including stat)

real    0m3.526s
user    0m0.540s
sys     0m2.987s
root@hydra-guix-127 ~ [env]# time ./links-traversal 
2017397 dir_entries, 3 seconds (including stat)

real    0m3.519s
user    0m0.600s
sys     0m2.919s
root@hydra-guix-127 ~ [env]# 
--8<---------------cut here---------------end--------------->8---

* mode 2 + lstat

--8<---------------cut here---------------start------------->8---
root@hydra-guix-127 ~ [env]# gcc -Wall -std=c99 links-traversal.c -DMODE=2 -D_GNU_SOURCE=1 -o links-traversal
root@hydra-guix-127 ~ [env]# echo 3 > /proc/sys/vm/drop_caches
root@hydra-guix-127 ~ [env]# time ./links-traversal 
17377 dir_entries, 9 seconds (including stat)

real    0m9.614s
user    0m1.205s
sys     0m4.250s
root@hydra-guix-127 ~ [env]# time ./links-traversal 
17377 dir_entries, 4 seconds (including stat)

real    0m4.060s
user    0m1.052s
sys     0m3.008s
root@hydra-guix-127 ~ [env]# time ./links-traversal 
17377 dir_entries, 4 seconds (including stat)

real    0m4.057s
user    0m0.984s
sys     0m3.073s
root@hydra-guix-127 ~ [env]# 
--8<---------------cut here---------------end--------------->8---

* mode 3 + lstat

--8<---------------cut here---------------start------------->8---
root@hydra-guix-127 ~ [env]# gcc -Wall -std=c99 links-traversal.c -DMODE=3 -D_GNU_SOURCE=1 -o links-traversal
root@hydra-guix-127 ~ [env]# echo 3 > /proc/sys/vm/drop_caches
root@hydra-guix-127 ~ [env]# time ./links-traversal 
2017397 dir_entries, 6 seconds
stat took 3 seconds

real    0m9.767s
user    0m1.270s
sys     0m4.339s
root@hydra-guix-127 ~ [env]# time ./links-traversal 
2017397 dir_entries, 2 seconds
stat took 2 seconds

real    0m4.234s
user    0m1.136s
sys     0m3.097s
root@hydra-guix-127 ~ [env]# time ./links-traversal 
2017397 dir_entries, 1 seconds
stat took 2 seconds

real    0m4.222s
user    0m1.052s
sys     0m3.170s
root@hydra-guix-127 ~ [env]# 
--8<---------------cut here---------------end--------------->8---

They are all very close, so I think I need to work with a bigger store
to see a difference.

Or perhaps I did something silly because I don’t know C…  If so please
let me know.

--
Ricardo