Subject: bug#38958: Timestamp out of range; substituting 2514-05-30 01:53:03.999999999

From: Ludovic Courtès <[email-masked]>
Date: Thu, 03 Sep 2020 10:54:17 +0200

Hi,

Roel Janssen <[email-masked]> skribis:

> I encounter a problem when running "make" for some code base:
> make[3]: /gnu/store/5hkc9q38w6afhrf7xyz5ybxidr87d1mq-profile/include/syslog.h:
> Timestamp out of range; substituting 2514-05-30 01:53:03.999999999

This issue manifests itself in build environments as well; I’ve seen it
on berlin while running “guix build guix --no-offload”:

--8<---------------cut here---------------start------------->8---
mv "doc/contributing.fr.texi.tmp" "doc/contributing.fr.texi"
  PO4A doc/contributing.zh_CN.texi
mv "doc/contributing.ru.texi.tmp" "doc/contributing.ru.texi"
make: guix/store/schema.sql: Timestamp out of range; substituting 2514-05-30 01:53:03.999999999
make: Warning: File 'guix/store/schema.sql' has modification time 15580747586 s in the future
  PO4A doc/guix-cookbook.de.texi
[…]
test ! -f guix.po || { \
  if test -f ./guix.pot; then \
    sed -f remove-potcdate.sed < ./guix.pot > guix.1po && \
    sed -f remove-potcdate.sed < guix.po > guix.2po && \
    if cmp guix.1po guix.2po >/dev/null 2>&1; then \
      rm -f guix.1po guix.2po guix.po; \
    else \
      rm -f guix.1po guix.2po ./guix.pot && \
      mv guix.po ./guix.pot; \
    fi; \
  else \
    mv guix.po ./guix.pot; \
  fi; \
}
make[3]: warning:  Clock skew detected.  Your build may be incomplete.
make[3]: Leaving directory '/tmp/guix-build-guix-1.1.0-25.44c6e6f.drv-0/source/po/guix'
[…]
make[2]: guix/base16.scm: Timestamp out of range; substituting 2514-05-30 01:53:03.999999999
make[2]: Warning: File 'guix/base16.scm' has modification time 15580748038 s in the future
make[2]: guix/base32.scm: Timestamp out of range; substituting 2514-05-30 01:53:03.999999999
[…]
make[2]: guix/search-paths.scm: Timestamp out of range; substituting 2514-05-30 01:53:03.999999999
make[2]: guix/import/gnu.scm: Timestamp out of range; substituting 2514-05-30 01:53:03.999999999
make[2]: guix/import/snix.scm: Timestamp out of range; substituting 2514-05-30 01:53:03.999999999
make[2]: guix/scripts/perform-download.scm: Timestamp out of range; substituting 2514-05-30 01:53:03.999999999
make[2]: guix/scripts/authenticate.scm: Timestamp out of range; substituting 2514-05-30 01:53:03.999999999
make[2]: guix/scripts/import/gnu.scm: Timestamp out of range; substituting 2514-05-30 01:53:03.999999999
make[2]: guix/scripts/import/nix.scm: Timestamp out of range; substituting 2514-05-30 01:53:03.999999999
make[2]: guix/scripts/import/texlive.scm: Timestamp out of range; substituting 2514-05-30 01:53:03.999999999
make[2]: guix/scripts/container.scm: Timestamp out of range; substituting 2514-05-30 01:53:03.999999999
make[2]: guix.scm: Timestamp out of range; substituting 2514-05-30 01:53:03.999999999
--8<---------------cut here---------------end--------------->8---

The files in question have mtime = Epoch + 1 as expected:

--8<---------------cut here---------------start------------->8---
$ stat /tmp/guix-build-guix-1.1.0-25.44c6e6f.drv-0/source/guix/base16.scm 
  File: /tmp/guix-build-guix-1.1.0-25.44c6e6f.drv-0/source/guix/base16.scm
  Size: 3251            Blocks: 8          IO Block: 4096   regular file
Device: 801h/2049d      Inode: 10880988    Links: 1
Access: (0444/-r--r--r--)  Uid: (30001/guixbuilder01)   Gid: (30000/guixbuild)
Access: 2020-09-03 10:18:35.594069572 +0200
Modify: 1970-01-01 00:00:01.000000000 +0100
Change: 2020-09-03 10:18:27.670122206 +0200
 Birth: 2020-09-03 10:18:27.670122206 +0200
$ stat /tmp/guix-build-guix-1.1.0-25.44c6e6f.drv-0/source/guix/base32.scm 
  File: /tmp/guix-build-guix-1.1.0-25.44c6e6f.drv-0/source/guix/base32.scm
  Size: 13325           Blocks: 32         IO Block: 4096   regular file
Device: 801h/2049d      Inode: 10881034    Links: 1
Access: (0444/-r--r--r--)  Uid: (30001/guixbuilder01)   Gid: (30000/guixbuild)
Access: 2020-09-03 10:18:35.594069572 +0200
Modify: 1970-01-01 00:00:01.000000000 +0100
Change: 2020-09-03 10:18:27.674122179 +0200
 Birth: 2020-09-03 10:18:27.674122179 +0200
$ stat /gnu/store/0br13w7y2wdfby74wnq7m7yzbx27hm1s-guix-1.1.0-25.44c6e6f-checkout/guix/base{16,32}.scm
  File: /gnu/store/0br13w7y2wdfby74wnq7m7yzbx27hm1s-guix-1.1.0-25.44c6e6f-checkout/guix/base16.scm
  Size: 3251            Blocks: 8          IO Block: 4096   regular file
Device: 811h/2065d      Inode: 344654478   Links: 10338
Access: (0444/-r--r--r--)  Uid: (    0/    root)   Gid: (    0/    root)
Access: 2020-09-03 09:36:43.818923620 +0200
Modify: 1970-01-01 00:00:01.000000000 +0100
Change: 2020-09-03 09:29:05.830024528 +0200
 Birth: 2018-06-25 22:37:25.560482991 +0200
  File: /gnu/store/0br13w7y2wdfby74wnq7m7yzbx27hm1s-guix-1.1.0-25.44c6e6f-checkout/guix/base32.scm
  Size: 13325           Blocks: 32         IO Block: 4096   regular file
Device: 811h/2065d      Inode: 344654504   Links: 9327
Access: (0444/-r--r--r--)  Uid: (    0/    root)   Gid: (    0/    root)
Access: 2020-09-03 09:36:43.822923593 +0200
Modify: 1970-01-01 00:00:01.000000000 +0100
Change: 2020-09-03 09:29:07.054016225 +0200
 Birth: 2018-06-25 22:37:25.682483782 +0200
--8<---------------cut here---------------end--------------->8---

In the output of ‘make’ above, guix/import/gnu.scm is listed, but not
guix/import/pypi.scm for instance.  What’s the difference?

--8<---------------cut here---------------start------------->8---
$ stat /tmp/guix-build-guix-1.1.0-25.44c6e6f.drv-0/source/guix/import/{gnu,pypi}.scm
  File: /tmp/guix-build-guix-1.1.0-25.44c6e6f.drv-0/source/guix/import/gnu.scm
  Size: 4714            Blocks: 16         IO Block: 4096   regular file
Device: 801h/2049d      Inode: 10881084    Links: 1
Access: (0444/-r--r--r--)  Uid: (30001/guixbuilder01)   Gid: (30000/guixbuild)
Access: 2020-09-03 10:26:30.745348482 +0200
Modify: 1970-01-01 00:00:01.000000000 +0100
Change: 2020-09-03 10:26:23.029400312 +0200
 Birth: 2020-09-03 10:26:23.029400312 +0200
  File: /tmp/guix-build-guix-1.1.0-25.44c6e6f.drv-0/source/guix/import/pypi.scm
  Size: 23270           Blocks: 48         IO Block: 4096   regular file
Device: 801h/2049d      Inode: 10881093    Links: 1
Access: (0444/-r--r--r--)  Uid: (30001/guixbuilder01)   Gid: (30000/guixbuild)
Access: 2020-09-03 10:26:30.745348482 +0200
Modify: 1970-01-01 01:00:01.000000000 +0100
Change: 2020-09-03 10:26:23.029400312 +0200
 Birth: 2020-09-03 10:26:23.029400312 +0200
--8<---------------cut here---------------end--------------->8---

Nothing obvious.

After checking the clock was fine, I turned off ntpd to be sure and
spawned another build, but the result was the same.

This is happening on berlin with a recent kernel:

--8<---------------cut here---------------start------------->8---
$ uname -rm
5.4.55-gnu x86_64
--8<---------------cut here---------------end--------------->8---

The GNU make warnings come from this impenetrable function:

--8<---------------cut here---------------start------------->8---
FILE_TIMESTAMP
file_timestamp_cons (const char *fname, time_t stamp, long int ns)
{
  int offset = ORDINARY_MTIME_MIN + (FILE_TIMESTAMP_HI_RES ? ns : 0);
  FILE_TIMESTAMP s = stamp;
  FILE_TIMESTAMP product = (FILE_TIMESTAMP) s << FILE_TIMESTAMP_LO_BITS;
  FILE_TIMESTAMP ts = product + offset;

  if (! (s <= FILE_TIMESTAMP_S (ORDINARY_MTIME_MAX)
         && product <= ts && ts <= ORDINARY_MTIME_MAX))
    {
      char buf[FILE_TIMESTAMP_PRINT_LEN_BOUND + 1];
      const char *f = fname ? fname : _("Current time");
      ts = s <= OLD_MTIME ? ORDINARY_MTIME_MIN : ORDINARY_MTIME_MAX;
      file_timestamp_sprintf (buf, ts);
      OSS (error, NILF,
           _("%s: Timestamp out of range; substituting %s"), f, buf);
    }

  return ts;
}
--8<---------------cut here---------------end--------------->8---

What’s OLD_MTIME?

--8<---------------cut here---------------start------------->8---
/* The file does not exist, and we assume that it is older than any
   actual file.  */
#define OLD_MTIME 2

/* The smallest and largest ordinary timestamps.  */
#define ORDINARY_MTIME_MIN (OLD_MTIME + 1)
--8<---------------cut here---------------end--------------->8---

That would mean that any file with mtime < 3 is considered bogus, but
then, why wouldn’t things fail on other machines as well?

I’m looking for ideas!  :-)

Ludo’.