GNU bug report logs - #77606
‘fdatasync’ on cached narinfo files is too expensive

Previous Next

Package: guix;

Reported by: Ludovic Courtès <ludovic.courtes <at> inria.fr>

Date: Mon, 7 Apr 2025 10:21:02 UTC

Severity: normal

Done: Ludovic Courtès <ludo <at> gnu.org>

Bug is archived. No further changes may be made.

Full log


Message #5 received at submit <at> debbugs.gnu.org (full text, mbox):

From: Ludovic Courtès <ludovic.courtes <at> inria.fr>
To: bug-guix <at> gnu.org
Subject: ‘fdatasync’ on cached narinfo files is too
 expensive
Date: Mon, 07 Apr 2025 12:20:26 +0200
Hello,

As Christopher Baines reported on IRC, calling ‘fdatasync’ on each
cached narinfo under /var/guix/substitute/cache can be unreasonably
expensive on spinning disks.

On bayfront, when tracing ‘guix substitute’ processes, we observe
‘fdatasync’ occasionally taking more than a second, and typically taking
more than 0.2s:

--8<---------------cut here---------------start------------->8---
mkdir("/var", 0777)                     = -1 EEXIST (File exists) <0.000048>
mkdir("/var/guix", 0777)                = -1 EEXIST (File exists) <0.000042>
mkdir("/var/guix/substitute", 0777)     = -1 EEXIST (File exists) <0.000040>
mkdir("/var/guix/substitute/cache", 0777) = -1 EEXIST (File exists) <0.000042>
mkdir("/var/guix/substitute/cache/kzwjeblndsbkjzmjailrt4bnhguil7tqjmewzcyw22hgajbhfy3q", 0777) = -1 EEXIST (File exists
) <0.000041>
clock_gettime(CLOCK_MONOTONIC, {tv_sec=153237, tv_nsec=595042938}) = 0 <0.000037>
openat(AT_FDCWD, "/var/guix/substitute/cache/kzwjeblndsbkjzmjailrt4bnhguil7tqjmewzcyw22hgajbhfy3q/nfmn2nkfjz5kzklw165aj
6ilwphw9zrz.3kAGMM", O_RDWR|O_CREAT|O_EXCL, 0600) = 15 <0.000123>
fstat(15, {st_mode=S_IFREG|0600, st_size=0, ...}) = 0 <0.000037>
lseek(15, 0, SEEK_CUR)                  = 0 <0.000038>
write(15, "(narinfo (version 2) (cache-uri "..., 1066) = 1066 <0.000071>
fdatasync(15)                           = 0 <1.860604>
--8<---------------cut here---------------end--------------->8---

A longer sample:

--8<---------------cut here---------------start------------->8---
ludo <at> bayfront ~$ grep ^fdatasync log.strace 
fdatasync(15)                           = 0 <1.860604>
fdatasync(15)                           = 0 <1.101868>
fdatasync(15)                           = 0 <0.464357>
fdatasync(15)                           = 0 <0.363363>
fdatasync(15)                           = 0 <0.307759>
fdatasync(15)                           = 0 <0.619979>
fdatasync(15)                           = 0 <0.269880>
fdatasync(15)                           = 0 <0.274093>
fdatasync(15)                           = 0 <0.247207>
fdatasync(15)                           = 0 <0.367507>
fdatasync(15)                           = 0 <0.212277>
fdatasync(15)                           = 0 <0.234929>
fdatasync(15)                           = 0 <0.330697>
fdatasync(15)                           = 0 <0.193925>
fdatasync(15)                           = 0 <0.251554>
fdatasync(15)                           = 0 <0.379571>
--8<---------------cut here---------------end--------------->8---

That call comes from ‘with-atomic-file-output’, commit
1752a17a1e6f7138892eeeb4806cd04ccb3ca1b0, which refers to this
discussion:

  https://lists.gnu.org/archive/html/guix-devel/2016-06/msg00456.html

It probably makes sense in some uses of ‘with-atomic-file-output’, but
nor for a cache as is the case here.

Ludo’.




This bug report was last modified 13 days ago.

Previous Next


GNU bug tracking system
Copyright (C) 1999 Darren O. Benham, 1997,2003 nCipher Corporation Ltd, 1994-97 Ian Jackson.