#24937 "deleting unused links" GC phase is too slow

Message #46 received at 24937@debbugs.gnu.org (full text, mbox, reply):

Received: (at 24937) by debbugs.gnu.org; 16 Apr 2020 14:27:39 +0000
From debbugs-submit-bounces@debbugs.gnu.org Thu Apr 16 10:27:39 2020
Received: from localhost ([127.0.0.1]:39057 helo=debbugs.gnu.org)
	by debbugs.gnu.org with esmtp (Exim 4.84_2)
	(envelope-from <debbugs-submit-bounces@debbugs.gnu.org>)
	id 1jP5UR-0001R0-FD
	for submit@debbugs.gnu.org; Thu, 16 Apr 2020 10:27:39 -0400
Received: from sender4-of-o53.zoho.com ([136.143.188.53]:21355)
 by debbugs.gnu.org with esmtp (Exim 4.84_2)
 (envelope-from <rekado@elephly.net>) id 1jP5UO-0001Qr-WE
 for 24937@debbugs.gnu.org; Thu, 16 Apr 2020 10:27:37 -0400
ARC-Seal: i=1; a=rsa-sha256; t=1587047252; cv=none; 
 d=zohomail.com; s=zohoarc; 
 b=NHpeWwxNlnaJkTstl3az5qdsq3TaO/yBVa6PMI4hji50I4E6E3Z9V+hqgo8OSxBUkmepJdt8CDnACfNV+CNvh9luUzDaoFoW67JgHQzfcdK9Gdz0Yfb8pOoODf/HqREKmNSnWhMWV8vgRDsQZP/WbnsPYNeoSmWbr1CDbyq3FWM=
ARC-Message-Signature: i=1; a=rsa-sha256; c=relaxed/relaxed; d=zohomail.com;
 s=zohoarc; t=1587047252;
 h=Content-Type:Cc:Date:From:In-Reply-To:MIME-Version:Message-ID:References:Subject:To;
 bh=yX8r1H9jQfw6U3NqRwnbd2CfuLzuWvduuq2wCfJT+sc=; 
 b=dCBJ76Q2ZTuq6LMeMOBHVIALZ4DdPwF0J/AgA8hcswdOAZy5EoVd/IYx4PMXcgPt3dh5XDac4ah2apbYmZD1r9j0A8H62H2nQko3eNncjnTpfxVy/496FDfkqZvD7xZjDb/9RenJTtnwVLhd/5NIEyjmv1LbjfkJc7524Lo37l0=
ARC-Authentication-Results: i=1; mx.zohomail.com;
 dkim=pass  header.i=elephly.net;
 spf=pass  smtp.mailfrom=rekado@elephly.net;
 dmarc=pass header.from=<rekado@elephly.net> header.from=<rekado@elephly.net>
DKIM-Signature: v=1; a=rsa-sha256; q=dns/txt; c=relaxed/relaxed; t=1587047252; 
 s=zoho; d=elephly.net; i=rekado@elephly.net;
 h=References:From:To:Cc:Subject:In-reply-to:Date:Message-ID:MIME-Version:Content-Type;
 bh=yX8r1H9jQfw6U3NqRwnbd2CfuLzuWvduuq2wCfJT+sc=;
 b=QMkHvnwIYRgXkq9pdA+rlA7Wbjd2JUo/Ak7FM1j/J2+zaHvfgQW2UjRJsJNKfROo
 chM1iBH0mEaKozWIAlhggmqAlFNpUeyw6xjJwYFKK6iHRQKM9ZAEWGwczLsPdTfim7k
 p52WXqLNjc18l82uaCn8zl+IHbA1pSqK6H50jPn4=
Received: from localhost (p54AD4D27.dip0.t-ipconnect.de [84.173.77.39]) by
 mx.zohomail.com with SMTPS id 1587047251175351.5640975176159;
 Thu, 16 Apr 2020 07:27:31 -0700 (PDT)
References: <87wpg7ffbm.fsf@gnu.org> <87lgvm4lzu.fsf@gnu.org>
 <87twaaa6j9.fsf@netris.org> <87twaa2vjx.fsf@gnu.org>
 <87lgvm9sgq.fsf@netris.org> <87d1gwvgu0.fsf@gnu.org>
 <87wpf4yoz0.fsf@netris.org> <87fulrsqxx.fsf@gnu.org>
 <87vaunbvcu.fsf@mdc-berlin.de> <87ftd3muhp.fsf@elephly.net>
User-agent: mu4e 1.2.0; emacs 26.3
From: Ricardo Wurmus <rekado@elephly.net>
To: Ludovic Courtès <ludo@gnu.org>
Subject: Re: bug#24937: "deleting unused links" GC phase is too slow
In-reply-to: <87ftd3muhp.fsf@elephly.net>
X-URL: https://elephly.net
X-PGP-Key: https://elephly.net/rekado.pubkey
X-PGP-Fingerprint: BCA6 89B6 3655 3801 C3C6  2150 197A 5888 235F ACAC
Date: Thu, 16 Apr 2020 16:27:27 +0200
Message-ID: <87eesnmrow.fsf@elephly.net>
MIME-Version: 1.0
Content-Type: multipart/mixed; boundary="=-=-="
X-Zoho-Virus-Status: 2
X-ZohoMailClient: External
X-Spam-Score: 0.0 (/)
X-Debbugs-Envelope-To: 24937
Cc: 24937@debbugs.gnu.org
X-BeenThere: debbugs-submit@debbugs.gnu.org
X-Mailman-Version: 2.1.18
Precedence: list
List-Id: <debbugs-submit.debbugs.gnu.org>
List-Unsubscribe: <https://debbugs.gnu.org/cgi-bin/mailman/options/debbugs-submit>, 
 <mailto:debbugs-submit-request@debbugs.gnu.org?subject=unsubscribe>
List-Archive: <https://debbugs.gnu.org/cgi-bin/mailman/private/debbugs-submit/>
List-Post: <mailto:debbugs-submit@debbugs.gnu.org>
List-Help: <mailto:debbugs-submit-request@debbugs.gnu.org?subject=help>
List-Subscribe: <https://debbugs.gnu.org/cgi-bin/mailman/listinfo/debbugs-submit>, 
 <mailto:debbugs-submit-request@debbugs.gnu.org?subject=subscribe>
Errors-To: debbugs-submit-bounces@debbugs.gnu.org
Sender: "Debbugs-submit" <debbugs-submit-bounces@debbugs.gnu.org>
X-Spam-Score: -1.0 (-)

[Message part 1 (text/plain, inline)]

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

[links-traversal-statx.c (application/octet-stream, attachment)]

Send a report that this bug log contains spam.