t3306 failure with v1.7.5-rc1

t3306 failure with v1.7.5-rc1

[Michael J Gruber]

Heya,

I get this stupid test failure in test 3 of t3306. The problem is that a
dangling commit does not get pruned away when it should:

3rd
test_must_fail: command succeeded: git cat-file -p
5ee1c35e83ea47cd3cc4f8cbee0568915fbbbd29
not ok - 4 verify that commits are gone

It's a system where make complains about funny clock (I dunno why) but
can we make this more robust? The following helps with "sleep 5" but not
with "sleep 4". test_tick does not help. What's going on?

---

diff --git i/t/t3306-notes-prune.sh w/t/t3306-notes-prune.sh
index c428217..da76463 100755
--- i/t/t3306-notes-prune.sh
+++ w/t/t3306-notes-prune.sh
@@ -62,7 +62,9 @@ test_expect_success 'remove some commits' '

 	git reset --hard HEAD~1 &&
 	git reflog expire --expire=now HEAD &&
+	sleep 5 &&
 	git gc --prune=now
 '

 test_expect_success 'verify that commits are gone' '

Re: t3306 failure with v1.7.5-rc1

[Johannes Sixt]

Am 4/8/2011 11:03, schrieb Michael J Gruber:
> I get this stupid test failure in test 3 of t3306. The problem is that a
> dangling commit does not get pruned away when it should:
> 
> 3rd
> test_must_fail: command succeeded: git cat-file -p
> 5ee1c35e83ea47cd3cc4f8cbee0568915fbbbd29
> not ok - 4 verify that commits are gone
> 
> It's a system where make complains about funny clock (I dunno why) but
> can we make this more robust? The following helps with "sleep 5" but not
> with "sleep 4". test_tick does not help. What's going on?

Looking at the time of day of your last emails (it's ~2 hours in the
future), I'd say something is fishy with your system's clock. Fix that first.

-- Hannes

Re: t3306 failure with v1.7.5-rc1

[Michael J Gruber]

Johannes Sixt venit, vidit, dixit 08.04.2011 09:06:
> Am 4/8/2011 11:03, schrieb Michael J Gruber:
>> I get this stupid test failure in test 3 of t3306. The problem is that a
>> dangling commit does not get pruned away when it should:
>>
>> 3rd
>> test_must_fail: command succeeded: git cat-file -p
>> 5ee1c35e83ea47cd3cc4f8cbee0568915fbbbd29
>> not ok - 4 verify that commits are gone
>>
>> It's a system where make complains about funny clock (I dunno why) but
>> can we make this more robust? The following helps with "sleep 5" but not
>> with "sleep 4". test_tick does not help. What's going on?
> 
> Looking at the time of day of your last emails (it's ~2 hours in the
> future), I'd say something is fishy with your system's clock. Fix that first.

Well, while you're right about that, an offset should not matter for the
test, right?

About my clock: The result of booting a "different" system on that
box... (In this case even a kubuntu using hw clock in tz...). thanks for
pointing it out!

In any case, that test was on a different box with clean checkout and
make clean. I don't think anyone jumped the clock right in between each
of my 20 or so test runs.

Michael

"prune" prone to clock skew (Re: t3306 failure with v1.7.5-rc1)

[Michael J Gruber]

Michael J Gruber venit, vidit, dixit 08.04.2011 09:13:
> Johannes Sixt venit, vidit, dixit 08.04.2011 09:06:
>> Am 4/8/2011 11:03, schrieb Michael J Gruber:
>>> I get this stupid test failure in test 3 of t3306. The problem is that a
>>> dangling commit does not get pruned away when it should:
>>>
>>> 3rd
>>> test_must_fail: command succeeded: git cat-file -p
>>> 5ee1c35e83ea47cd3cc4f8cbee0568915fbbbd29
>>> not ok - 4 verify that commits are gone
>>>
>>> It's a system where make complains about funny clock (I dunno why) but

(I know now.)

>>> can we make this more robust? The following helps with "sleep 5" but not
>>> with "sleep 4". test_tick does not help. What's going on?

Adding one more observation from that system:

rm GIT-VERSION-FILE ;date; sh ./GIT-VERSION-GEN; date; ls -l --full-time
GIT-VERSION-FILE

Fri Apr  8 09:27:40 CEST 2011
GIT_VERSION = 1.7.5.rc1
Fri Apr  8 09:27:41 CEST 2011
-rw-r----- 1 mjg mjg 24 2011-04-08 09:27:47.000000000 +0200 GIT-VERSION-FILE

Note that the second "date" happens after the creation of
GIT-VERSION-FILE. I can even do this with a simple

rm a;date; touch a; date; ls -l --full-time a
Fri Apr  8 09:31:04 CEST 2011
Fri Apr  8 09:31:04 CEST 2011
-rw-r----- 1 mjg mjg 0 2011-04-08 09:31:11.000000000 +0200 a

Suffice it to say that this is on NFS, and of course the creation date
comes from the NFS server, the "date" from the client... OK, I got that.
Scary.

EXPLANATION:

I guess "prune" looks at some file time stamps (rather than parsing the
commit time proper) so that it is prone to the same client/server clock
skew problems when the repo is not on the local file system.

PROBLEM (?):

I really hope this does not go both ways - imagine a messed server
turning it's clock a few weeks back by accident, and running "git prune"
on the client, or a messed client turning the clock forward... Do we do
proper checks before removing something?

I mean, there's a difference between missing that something is stale and
missing that it is not...

Michael

Re: "prune" prone to clock skew (Re: t3306 failure with v1.7.5-rc1)

[Jeff King]

On Fri, Apr 08, 2011 at 09:41:53AM +0200, Michael J Gruber wrote:

> EXPLANATION:
> 
> I guess "prune" looks at some file time stamps (rather than parsing the
> commit time proper) so that it is prone to the same client/server clock
> skew problems when the repo is not on the local file system.

Of course. Remember that prune is removing all sorts of objects, not
just commits. In the case of a tree or blob, we have nothing else to go
on besides the filesystem timestamp.

> PROBLEM (?):
> 
> I really hope this does not go both ways - imagine a messed server
> turning it's clock a few weeks back by accident, and running "git prune"
> on the client, or a messed client turning the clock forward... Do we do
> proper checks before removing something?

I don't think anybody has ever cared. These things are, after all,
unreferenced by either current refs or the reflog. I think the purpose
of the 2-week grace period is more to prevent prune from deleting
objects from an in-progress operation before that operation has had a
chance to write its refs.

So one problem scenario is that the prune on the machine with the bad
clock would delete objects from something like a push in progress.

But I think it's just so unlikely to happen that your repo is on a
remote server, _and_ the client and server clocks are skewed by more
than two weeks, _and_ you're running prune, _and_ somebody is pushing
into the repo simultaneously, that nobody has really bothered to try to
do better.

Note that if you access the same repo over a filesystem share by two
clients with different clocks, you can also expire reflog entries
prematurely. But that is a 90-day window.

So I don't know that it's worth fixing, nor do I know what your "proper
checks" would be. We could open up commits we're about to prune and
check their timestamps for age. That wouldn't help blobs and trees. For
them, we could make a guess as to their age by seeing if they're
connected to any dangling commits, and using the commit timestamp. But
that will only cover some objects, and it is also still vulnerable to
certain types of clock skew (though it is more robust, since you would
need a client and server with one type writing the objects, and then
another skewed client doing the prune, which is even less likely).

-Peff

Re: "prune" prone to clock skew (Re: t3306 failure with v1.7.5-rc1)

[Junio C Hamano]

Jeff King <peff@peff.net> writes:

> So I don't know that it's worth fixing, nor do I know what your "proper
> checks" would be. We could open up commits we're about to prune and
> check their timestamps for age. That wouldn't help blobs and trees. For
> them, we could make a guess as to their age by seeing if they're
> connected to any dangling commits, and using the commit timestamp. But
> that will only cover some objects, and it is also still vulnerable to
> certain types of clock skew (though it is more robust, since you would
> need a client and server with one type writing the objects, and then
> another skewed client doing the prune, which is even less likely).

I don't personally think this is worth addressing, but as I was Cc'ed,
I'll try.

If we at least know that the object store is contained within a single
filesystem whose clock is at least guaranteed to monotonically increase,
one possible workaround would be to touch a garbage file and read its
timestamp, instead of grabbing the current time from the local clock, no?

Re: "prune" prone to clock skew (Re: t3306 failure with v1.7.5-rc1)

[Jeff King]

On Fri, Apr 08, 2011 at 11:51:10AM -0700, Junio C Hamano wrote:

> I don't personally think this is worth addressing, but as I was Cc'ed,
> I'll try.
> 
> If we at least know that the object store is contained within a single
> filesystem whose clock is at least guaranteed to monotonically increase,
> one possible workaround would be to touch a garbage file and read its
> timestamp, instead of grabbing the current time from the local clock, no?

Yeah, that is a much more accurate and simpler fix. Like you, I don't
really think it's worth worrying about, but if somebody wanted to, that
is much better than the fix I mentioned.

-Peff