Re: [PATCH] t4212: handle systems with post-apocalyptic gmtime

Jeff King [off-list ref] writes:

+cmp_one_of () {
+	for candidate in "$@"; do

Style ;-)

+		echo "$candidate" >expect &&
+		test_cmp expect actual &&
+		return 0
+	done
+	return 1
+}

It actually may be easier to understand if you write a trivial case
statement at the sole calling site of this helper function, though.

In any case, would it really be essential to make sure that the
output shows a phony (or a seemingly real) datestamp for this test?

The primary thing you wanted to achieve by the "gmtime gave us NULL,
let's substitute it with an arbitrary value to avoid dereferencing
the NULL" change was *not* that we see that same arbitrary value
comes out of the system, but that we do not die by attempting to
reference the NULL, I think.  Not dying is the primary thing we want
to (and we already do) test, no?

+# date is within 2^63-1, but enough to choke glibc's gmtime.
+# We check that either the date broke gmtime (and we return the
+# usual epoch value), or gmtime gave us some sensible value.
+#
+# The sensible values are determined experimentally. The first
+# is from AIX.
+test_expect_success 'absurdly far-in-future dates' '
 	commit=$(munge_author_date HEAD 999999999999999999) &&
-	echo "Thu Jan 1 00:00:00 1970 +0000" >expect &&
 	git log -1 --format=%ad $commit >actual &&
-	test_cmp expect actual
+	cmp_one_of \
+		"Thu Jan 1 00:00:00 1970 +0000" \
+		"Thu Oct 24 18:46:39 162396404 -0700"
 '
 
 test_done

On Wed, Mar 26, 2014 at 12:18:25PM -0700, Junio C Hamano wrote:

quoted

+		echo "$candidate" >expect &&
+		test_cmp expect actual &&
+		return 0
+	done
+	return 1
+}

It actually may be easier to understand if you write a trivial case
statement at the sole calling site of this helper function, though.

Yeah, perhaps. I wanted to build on test_cmp because it has nice output
for the failure case, but it is probably simple enough to do:

  output=$(cat actual)
  case "$output" in
  ...
  *) echo >&2 "unrecognized date: $output"

In any case, would it really be essential to make sure that the
output shows a phony (or a seemingly real) datestamp for this test?

The primary thing you wanted to achieve by the "gmtime gave us NULL,
let's substitute it with an arbitrary value to avoid dereferencing
the NULL" change was *not* that we see that same arbitrary value
comes out of the system, but that we do not die by attempting to
reference the NULL, I think.  Not dying is the primary thing we want
to (and we already do) test, no?

I think there are really two separate behaviors we are testing here (and
in the surrounding tests):

  1. Don't segfault if gmtime returns NULL.

  2. Whenever we cannot process a date (either because gmtime fails, or
     because we fail before even getting the value to gmtime),
     consistently return the sentinel date (so the reader can easily
     know it's bogus).

Having the test be particular about its output helped us find a case
where FreeBSD did not trigger (1), but did trigger (2), by returning a
blanked "struct tm".

I'm open to the argument that (2) is not worth worrying about that much
if it is a hassle to test. But I don't think it is that much hassle
(yet, anyway).

-Peff

On Wed, Mar 26, 2014 at 03:25:36PM -0400, Jeff King wrote:

quoted

The primary thing you wanted to achieve by the "gmtime gave us NULL,
let's substitute it with an arbitrary value to avoid dereferencing
the NULL" change was *not* that we see that same arbitrary value
comes out of the system, but that we do not die by attempting to
reference the NULL, I think.  Not dying is the primary thing we want
to (and we already do) test, no?

I think there are really two separate behaviors we are testing here (and
in the surrounding tests):

  1. Don't segfault if gmtime returns NULL.

  2. Whenever we cannot process a date (either because gmtime fails, or
     because we fail before even getting the value to gmtime),
     consistently return the sentinel date (so the reader can easily
     know it's bogus).

Having the test be particular about its output helped us find a case
where FreeBSD did not trigger (1), but did trigger (2), by returning a
blanked "struct tm".

I'm open to the argument that (2) is not worth worrying about that much
if it is a hassle to test. But I don't think it is that much hassle
(yet, anyway).

That being said, is the AIX value actually right? I did not look closely
at first, but just assumed that it was vaguely right. But:

  999999999999999999 / (86400 * 365)

is something like 31 billion years in the future, not 160 million.
A real date calculation will have a few tweaks (leap years, etc), but
that is orders of magnitude off.

So I am not sure that AIX is not actually just giving us utter crap. In
that case, the test is not wrong; it's pickiness is actually finding a
real problem. But I am not sure it is a problem worth solving. I do not
want to get into heuristics deciding whether a particular platform's
gmtime output is crap or not. That pushes this into the realm of "it's
not worth testing", and we should stick to just testing that we did not
segfault.

-Peff

On Wed, Mar 26, 2014 at 03:33:59PM -0400, Jeff King wrote:

That being said, is the AIX value actually right? I did not look closely
at first, but just assumed that it was vaguely right. But:

  999999999999999999 / (86400 * 365)

is something like 31 billion years in the future, not 160 million.
A real date calculation will have a few tweaks (leap years, etc), but
that is orders of magnitude off.

Assuming my math is right, then here is the most sensible patch, IMHO.

-- >8 --
Subject: t4212: loosen far-in-future test for AIX

One of the tests in t4212 checks our behavior when we feed
gmtime a date so far in the future that it gives up and
returns NULL. Some implementations, like AIX, may actually
just provide us a bogus result instead.

It's not worth it for us to come up with heuristics that
guess whether the return value is sensible or not. On good
platforms where gmtime reports the problem to us with NULL,
we will print the epoch value. On bad platforms, we will
print garbage.  But our test should be written for the
lowest common denominator so that it passes everywhere.

Reported-by: Charles Bailey <redacted>
Signed-off-by: Jeff King <redacted>
---
 t/t4212-log-corrupt.sh | 11 +++++++----
 1 file changed, 7 insertions(+), 4 deletions(-)

diff --git a/t/t4212-log-corrupt.sh b/t/t4212-log-corrupt.sh
index 85c6df4..bb843ab 100755
--- a/t/t4212-log-corrupt.sh
+++ b/t/t4212-log-corrupt.sh

@@ -77,11 +77,14 @@ test_expect_success 'date parser recognizes time_t overflow' '
 '
 
 # date is within 2^63-1, but enough to choke glibc's gmtime
-test_expect_success 'absurdly far-in-future dates produce sentinel' '
+#
+# Ideally we would check the output to make sure we replaced it with
+# a useful sentinel value, but some platforms will actually hand us back
+# a nonsensical date. It is not worth our time to try to evaluate these
+# dates, so just make sure we didn't segfault or otherwise abort.
+test_expect_success 'absurdly far-in-future dates' '
 	commit=$(munge_author_date HEAD 999999999999999999) &&
-	echo "Thu Jan 1 00:00:00 1970 +0000" >expect &&
-	git log -1 --format=%ad $commit >actual &&
-	test_cmp expect actual
+	git log -1 --format=%ad $commit
 '
 
 test_done

-- 
1.9.1.656.ge8a0637

On Wed, Mar 26, 2014 at 03:40:43PM -0400, Jeff King wrote:

On Wed, Mar 26, 2014 at 03:33:59PM -0400, Jeff King wrote:

quoted

That being said, is the AIX value actually right? I did not look closely
at first, but just assumed that it was vaguely right. But:

  999999999999999999 / (86400 * 365)

is something like 31 billion years in the future, not 160 million.
A real date calculation will have a few tweaks (leap years, etc), but
that is orders of magnitude off.

Assuming my math is right, then here is the most sensible patch, IMHO.

Perhaps hold onto this one for a little while longer. Splitting things
out from the test is giving me some inconsistent results, there may be
something else going wrong in our environment here.

Charles.

On Wed, Mar 26, 2014 at 08:36:18PM +0000, Charles Bailey wrote:

On Wed, Mar 26, 2014 at 03:40:43PM -0400, Jeff King wrote:

quoted

On Wed, Mar 26, 2014 at 03:33:59PM -0400, Jeff King wrote:

quoted

That being said, is the AIX value actually right? I did not look closely
at first, but just assumed that it was vaguely right. But:

  999999999999999999 / (86400 * 365)

is something like 31 billion years in the future, not 160 million.
A real date calculation will have a few tweaks (leap years, etc), but
that is orders of magnitude off.

Assuming my math is right, then here is the most sensible patch, IMHO.

Perhaps hold onto this one for a little while longer. Splitting things
out from the test is giving me some inconsistent results, there may be
something else going wrong in our environment here.

By the way, can you confirm that this is a 64-bit system? On a 32-bit
system, we should be triggering different code paths (we fail at the
strtoul level). Those should be checked by the previous tests, but I'd
like to make sure.

-Peff

On Wed, Mar 26, 2014 at 04:38:30PM -0400, Jeff King wrote:

By the way, can you confirm that this is a 64-bit system? On a 32-bit
system, we should be triggering different code paths (we fail at the
strtoul level). Those should be checked by the previous tests, but I'd
like to make sure.

Yes, we're only building 64-bit at the moment.

On Wed, Mar 26, 2014 at 03:33:59PM -0400, Jeff King wrote:

That being said, is the AIX value actually right? I did not look closely
at first, but just assumed that it was vaguely right. But:

  999999999999999999 / (86400 * 365)

is something like 31 billion years in the future, not 160 million.
A real date calculation will have a few tweaks (leap years, etc), but
that is orders of magnitude off.

Well, this is embarrassing, while moving this through the corporate
firewall (aka typing on one machine while looking at another), I
munged the date. It still doesn't seem right but at least you can now
see the actual data.

I stopped the test with --immediate and found the dangling commit that
the test created and dumped it with the previous version of Git (well
a 1.8.5.5 build)

  ibm: trash directory.t4212-log-corrupt $ git log -1 --pretty=raw 1fc17e734e4487c31bdfe05bb3d15618b69c4dca
  commit 1fc17e734e4487c31bdfe05bb3d15618b69c4dca
  tree 64fd3796c57084e7b8cbae358ce37970b8e954f6
  author A U Thor [off-list ref] 999999999999999999 -0700
  committer C O Mitter [off-list ref] 1112911993 -0700

      foo

  ibm: trash directory.t4212-log-corrupt $ git log -1 1fc17e734e4487c31bdfe05bb3d15618b69c4dca
  commit 1fc17e734e4487c31bdfe05bb3d15618b69c4dca
  Author: A U Thor [off-list ref]
  Date:   Thu Oct 24 18:46:39 1623969404 -0700

      foo

Same commit but dumped from a linux machine:

  linux: trash directory.t4212-log-corrupt $ git log -1 1fc17e734e4487c31bdfe05bb3d15618b69c4dca
  commit 1fc17e734e4487c31bdfe05bb3d15618b69c4dca
  Author: A U Thor [off-list ref]
  Date:   (null)

      foo

Charles.

On Wed, Mar 26, 2014 at 09:22:27PM +0000, Charles Bailey wrote:

On Wed, Mar 26, 2014 at 03:33:59PM -0400, Jeff King wrote:

quoted

That being said, is the AIX value actually right? I did not look closely
at first, but just assumed that it was vaguely right. But:

  999999999999999999 / (86400 * 365)

is something like 31 billion years in the future, not 160 million.
A real date calculation will have a few tweaks (leap years, etc), but
that is orders of magnitude off.

Well, this is embarrassing, while moving this through the corporate
firewall (aka typing on one machine while looking at another), I
munged the date. It still doesn't seem right but at least you can now
see the actual data.

Hmm, so the year you got is actually: 1623969404. That still seems off
to me by a factor 20. I don't know if this is really worth digging into
that much further, but I wonder what you would get for timestamps of:

  99999999999999999
  9999999999999999
  999999999999999
  etc.

Do we start generating weird values at some particular size? Or is AIX
gmtime really more clever than I am, and is accounting for wobble of the
Earth or something over the next billion years?

-Peff

On Wed, Mar 26, 2014 at 05:57:41PM -0400, Jeff King wrote:

Hmm, so the year you got is actually: 1623969404. That still seems off
to me by a factor 20. I don't know if this is really worth digging into
that much further, but I wonder what you would get for timestamps of:

  99999999999999999
  9999999999999999
  999999999999999
  etc.

AIX goes negative at about the same time Linux and Solaris segfault:

9999999 Sun Apr 26 10:46:39 1970 -0700
99999999 Sat Mar 3 02:46:39 1973 -0700
999999999 Sat Sep 8 18:46:39 2001 -0700
9999999999 Sat Nov 20 10:46:39 2286 -0700
99999999999 Wed Nov 16 02:46:39 5138 -0700
999999999999 Thu Sep 26 18:46:39 33658 -0700
9999999999999 Sun May 20 10:46:39 318857 -0700
99999999999999 Sat Nov 7 02:46:39 3170843 -0700
999999999999999 Sat Jul 4 18:46:39 31690708 -0700
9999999999999999 Sat Jan 25 10:46:39 316889355 -0700
99999999999999999 Wed Sep 6 02:46:39 -1126091476 -0700
999999999999999999 Thu Oct 24 18:46:39 1623969404 -0700

So, very bogus values.

Charles.

On Wed, Mar 26, 2014 at 10:46:16PM +0000, Charles Bailey wrote:

On Wed, Mar 26, 2014 at 05:57:41PM -0400, Jeff King wrote:

quoted

Hmm, so the year you got is actually: 1623969404. That still seems off
to me by a factor 20. I don't know if this is really worth digging into
that much further, but I wonder what you would get for timestamps of:

  99999999999999999
  9999999999999999
  999999999999999
  etc.

AIX goes negative at about the same time Linux and Solaris segfault:

9999999 Sun Apr 26 10:46:39 1970 -0700
99999999 Sat Mar 3 02:46:39 1973 -0700
999999999 Sat Sep 8 18:46:39 2001 -0700
9999999999 Sat Nov 20 10:46:39 2286 -0700
99999999999 Wed Nov 16 02:46:39 5138 -0700
999999999999 Thu Sep 26 18:46:39 33658 -0700
9999999999999 Sun May 20 10:46:39 318857 -0700
99999999999999 Sat Nov 7 02:46:39 3170843 -0700
999999999999999 Sat Jul 4 18:46:39 31690708 -0700
9999999999999999 Sat Jan 25 10:46:39 316889355 -0700
99999999999999999 Wed Sep 6 02:46:39 -1126091476 -0700
999999999999999999 Thu Oct 24 18:46:39 1623969404 -0700

Thanks. Given the value where it fails, it kind of looks like there is
some signed 32-bit value at work (~300 million years is OK, but 10 times
that, rather than yielding ~3 billion, gets us -1 billion). Perhaps
tm.tm_year is 32-bit.

So what do we want to do? I think the options are:

  1. Try to guess when we have a bogus timestamp value with an arbitrary
     cutoff like "greater than 1 million years from now" (and enforce it
     via time_t seconds, and avoid gmtime entirely). That is made-up and
     arbitrary, but it also is sufficiently far that it won't ever
     matter, and sufficiently close that any gmtime should behave
     sensibly with it.

  2. Accept that we can't guess at every broken gmtime's output, and
     just loosen the test to make sure we don't segfault.

-Peff