{"thread":{"id":"53813","subject":"[PATCH] Make some commit hashes in tests reproducible","startedAt":"2020-07-07T19:23:29Z","lastAt":"2020-07-08T05:06:36Z","messageCount":8,"participants":["Han-Wen Nienhuys via GitGitGadget","Junio C Hamano","Jeff King","Han-Wen Nienhuys"],"isPatch":true,"patchVersion":1,"patchTotal":null},"messages":[{"id":"401147","messageId":"pull.816.git.git.1594149804313.gitgitgadget@gmail.com","threadId":"53813","inReplyTo":null,"subject":"[PATCH] Make some commit hashes in tests reproducible","fromName":"Han-Wen Nienhuys via GitGitGadget","fromEmail":"gitgitgadget@gmail.com","sentAt":"2020-07-07T19:23:24Z","receivedAt":"2020-07-07T19:23:29Z","isPatch":true,"sender":{"key":"hanwen@google.com","avatar":"https://avatars.githubusercontent.com/u/31547?v=4"},"body":"From: Han-Wen Nienhuys \n\nAdds test_tick to t5801-remote-helpers.sh and t3203-branch-output.sh\n\nSigned-off-by: Han-Wen Nienhuys \n---\n Make commit hashes in test t3203-branch-output.sh reproducible\n \n Signed-off-by: Han-Wen Nienhuys hanwen@google.com [hanwen@google.com]\n\nPublished-As: https://github.com/gitgitgadget/git/releases/tag/pr-git-816%2Fhanwen%2Frepro-hash-v1\nFetch-It-Via: git fetch https://github.com/gitgitgadget/git pr-git-816/hanwen/repro-hash-v1\nPull-Request: https://github.com/git/git/pull/816\n\n t/t3203-branch-output.sh | 2 ++\n t/t5801-remote-helpers.sh | 2 ++\n 2 files changed, 4 insertions(+)\n\ndiff --git a/t/t3203-branch-output.sh b/t/t3203-branch-output.sh\nindex 71818b90f0..6b614739af 100755\n--- a/t/t3203-branch-output.sh\n+++ b/t/t3203-branch-output.sh\n@@ -4,6 +4,8 @@ test_description='git branch display tests'\n . ./test-lib.sh\n . \"$TEST_DIRECTORY\"/lib-terminal.sh\n \n+test_tick\n+\n test_expect_success 'make commits' '\n \techo content >file &&\n \tgit add file &&\ndiff --git a/t/t5801-remote-helpers.sh b/t/t5801-remote-helpers.sh\nindex 0f04b6cddb..de51584173 100755\n--- a/t/t5801-remote-helpers.sh\n+++ b/t/t5801-remote-helpers.sh\n@@ -22,6 +22,8 @@ compare_refs() {\n \teval $fail test_cmp expect actual\n }\n \n+test_tick\n+\n test_expect_success 'setup repository' '\n \tgit init server &&\n \t(cd server &&\n\nbase-commit: a08a83db2bf27f015bec9a435f6d73e223c21c5e\n-- \ngitgitgadget\n"},{"id":"401151","messageId":"xmqqfta33y0m.fsf@gitster.c.googlers.com","threadId":"53813","inReplyTo":"pull.816.git.git.1594149804313.gitgitgadget@gmail.com","subject":"Re: [PATCH] Make some commit hashes in tests reproducible","fromName":"Junio C Hamano","fromEmail":"gitster@pobox.com","sentAt":"2020-07-07T19:50:33Z","receivedAt":"2020-07-07T19:50:41Z","isPatch":true,"sender":{"key":"gitster@pobox.com","avatar":"https://avatars.githubusercontent.com/u/54884?v=4"},"body":"\"Han-Wen Nienhuys via GitGitGadget\" writes:\n\n> From: Han-Wen Nienhuys \n>\n> Adds test_tick to t5801-remote-helpers.sh and t3203-branch-output.sh\n\nThat can be read from the patch. Also the subject tells us a half\nof what you want to achieve with this change (by the way, your\nsubject is malformatted and lacks the : prefix; perhaps\n\"[PATCH] tests: make commit object names reproducible\" or something),\nbut the readers are left hanging without knowing what motivated the\nchange. Do any test pieces in these scripts change their behaviour\nbased on what exact object names are assigned to them, making them\nflaky and hard to test, and if so which one and in what way?\n\nThanks.\n\n> Signed-off-by: Han-Wen Nienhuys \n> ---\n> Make commit hashes in test t3203-branch-output.sh reproducible\n> \n> Signed-off-by: Han-Wen Nienhuys hanwen@google.com [hanwen@google.com]\n>\n> Published-As: https://github.com/gitgitgadget/git/releases/tag/pr-git-816%2Fhanwen%2Frepro-hash-v1\n> Fetch-It-Via: git fetch https://github.com/gitgitgadget/git pr-git-816/hanwen/repro-hash-v1\n> Pull-Request: https://github.com/git/git/pull/816\n>\n> t/t3203-branch-output.sh | 2 ++\n> t/t5801-remote-helpers.sh | 2 ++\n> 2 files changed, 4 insertions(+)\n>\n> diff --git a/t/t3203-branch-output.sh b/t/t3203-branch-output.sh\n> index 71818b90f0..6b614739af 100755\n> --- a/t/t3203-branch-output.sh\n> +++ b/t/t3203-branch-output.sh\n> @@ -4,6 +4,8 @@ test_description='git branch display tests'\n> . ./test-lib.sh\n> . \"$TEST_DIRECTORY\"/lib-terminal.sh\n> \n> +test_tick\n> +\n> test_expect_success 'make commits' '\n> \techo content >file &&\n> \tgit add file &&\n> diff --git a/t/t5801-remote-helpers.sh b/t/t5801-remote-helpers.sh\n> index 0f04b6cddb..de51584173 100755\n> --- a/t/t5801-remote-helpers.sh\n> +++ b/t/t5801-remote-helpers.sh\n> @@ -22,6 +22,8 @@ compare_refs() {\n> \teval $fail test_cmp expect actual\n> }\n> \n> +test_tick\n> +\n> test_expect_success 'setup repository' '\n> \tgit init server &&\n> \t(cd server &&\n>\n> base-commit: a08a83db2bf27f015bec9a435f6d73e223c21c5e\n"},{"id":"401153","messageId":"20200707205418.GB1396940@coredump.intra.peff.net","threadId":"53813","inReplyTo":"xmqqfta33y0m.fsf@gitster.c.googlers.com","subject":"Re: [PATCH] Make some commit hashes in tests reproducible","fromName":"Jeff King","fromEmail":"peff@peff.net","sentAt":"2020-07-07T20:54:18Z","receivedAt":"2020-07-07T20:54:21Z","isPatch":true,"sender":{"key":"peff@peff.net","avatar":"https://avatars.githubusercontent.com/u/45925?v=4"},"body":"On Tue, Jul 07, 2020 at 12:50:33PM -0700, Junio C Hamano wrote:\n\n> \"Han-Wen Nienhuys via GitGitGadget\" writes:\n> \n> > From: Han-Wen Nienhuys \n> >\n> > Adds test_tick to t5801-remote-helpers.sh and t3203-branch-output.sh\n> \n> That can be read from the patch. Also the subject tells us a half\n> of what you want to achieve with this change (by the way, your\n> subject is malformatted and lacks the : prefix; perhaps\n> \"[PATCH] tests: make commit object names reproducible\" or something),\n> but the readers are left hanging without knowing what motivated the\n> change. Do any test pieces in these scripts change their behaviour\n> based on what exact object names are assigned to them, making them\n> flaky and hard to test, and if so which one and in what way?\n\nI agree that more discussion would be nice.\n\nBut I kind of wonder if we should be aiming for more determinism in\ngeneral, just to make debugging and reproduction simpler.\n\nI.e., rather than pointing to _these_ tests, I think we could make an\nargument for setting up a known timestamp in the test environment.\ntest_tick would continue to tick forward as usual, but for any tests\nthat don't use it, they'd by default get a deterministic outcome.\n\nSomething like this:\n\ndiff --git a/t/test-lib.sh b/t/test-lib.sh\nindex 618a7c8d5b..d8adf5a199 100644\n--- a/t/test-lib.sh\n+++ b/t/test-lib.sh\n@@ -441,15 +441,18 @@ TEST_AUTHOR_LOCALNAME=author\n TEST_AUTHOR_DOMAIN=example.com\n GIT_AUTHOR_EMAIL=${TEST_AUTHOR_LOCALNAME}@${TEST_AUTHOR_DOMAIN}\n GIT_AUTHOR_NAME='A U Thor'\n+GIT_AUTHOR_DATE='1112911993 -0700'\n TEST_COMMITTER_LOCALNAME=committer\n TEST_COMMITTER_DOMAIN=example.com\n GIT_COMMITTER_EMAIL=${TEST_COMMITTER_LOCALNAME}@${TEST_COMMITTER_DOMAIN}\n GIT_COMMITTER_NAME='C O Mitter'\n+GIT_COMMITTER_DATE='1112911993 -0700'\n GIT_MERGE_VERBOSITY=5\n GIT_MERGE_AUTOEDIT=no\n export GIT_MERGE_VERBOSITY GIT_MERGE_AUTOEDIT\n export GIT_AUTHOR_EMAIL GIT_AUTHOR_NAME\n export GIT_COMMITTER_EMAIL GIT_COMMITTER_NAME\n+export GIT_COMMITTER_DATE GIT_AUTHOR_DATE\n export EDITOR\n \n # Tests using GIT_TRACE typically don't want : output\n\nThat's using the same start point as test_tick, though really it could\nbe anything. I've intentionally _not_ called test_tick at the beginning\nof each script, because that would throw off all of the scripts that do\nuse it by one tick (whereas the first test_tick will overwrite these\nvalues).\n\nTrying to devil's advocate against this line of reasoning:\n\n - using the current timestamp introduces more randomness into the test\n suite, which could uncover problems. I'm somewhat skeptical, as the\n usual outcome I see here is that we realize a test's expected output\n is simply racy, and we remove the raciness by using test_tick\n\n - using the current timestamp could alert us to problems that occur\n only as the clock ticks forward (e.g., if we had a Y2021 bug, we'd\n notice when the clock rolled forward).\n\n - some tests may rely on having a \"recent\" timestamp in commits (e.g.,\n when looking at relative date handling). I think all of the\n relative-time tests already use a specific date, though, because\n otherwise we have too many problems with raciness.\n\nNote that the patch above does seem to cause two tests to fail. One of\nthem I _suspect_ is a raciness problem (order of commits output changes,\nwhich implies the original was expecting the time to increment between\ntwo commits without running test_tick). And the other looks like some\nweird interaction with the perl test harness. I'd be happy to dig into\nboth if this direction seems sane.\n\n-Peff\n"},{"id":"401156","messageId":"xmqq1rln3t4y.fsf@gitster.c.googlers.com","threadId":"53813","inReplyTo":"20200707205418.GB1396940@coredump.intra.peff.net","subject":"Re: [PATCH] Make some commit hashes in tests reproducible","fromName":"Junio C Hamano","fromEmail":"gitster@pobox.com","sentAt":"2020-07-07T21:35:57Z","receivedAt":"2020-07-07T21:36:04Z","isPatch":true,"sender":{"key":"gitster@pobox.com","avatar":"https://avatars.githubusercontent.com/u/54884?v=4"},"body":"Jeff King writes:\n\n> That's using the same start point as test_tick, though really it could\n> be anything. I've intentionally _not_ called test_tick at the beginning\n> of each script, because that would throw off all of the scripts that do\n> use it by one tick (whereas the first test_tick will overwrite these\n> values).\n\nYup, I think that is a sensible approach.\n\n> Trying to devil's advocate against this line of reasoning:\n>\n> - using the current timestamp introduces more randomness into the test\n> suite, which could uncover problems. I'm somewhat skeptical, as the\n> usual outcome I see here is that we realize a test's expected output\n> is simply racy, and we remove the raciness by using test_tick\n\nTrue.\n\n> - using the current timestamp could alert us to problems that occur\n> only as the clock ticks forward (e.g., if we had a Y2021 bug, we'd\n> notice when the clock rolled forward).\n\nTrue.\n\n> - some tests may rely on having a \"recent\" timestamp in commits (e.g.,\n> when looking at relative date handling). I think all of the\n> relative-time tests already use a specific date, though, because\n> otherwise we have too many problems with raciness.\n\nTrue.\n\nAnother thing we could do is under DEVELOPER=YesPlease we can set\ntimestamps you just added here to some random time.\n\nThe ones that do care about reproducibility guarantee by using\ntest_tick would not be affected, and those that were happy with the\ncurrent time should be happy with such a random timestamp. Or we\ncould just drop what this patch does only under DEVELOPER=YesPlease\nwhich amounts to be the same as setting random time.\n\n> Note that the patch above does seem to cause two tests to fail. One of\n> them I _suspect_ is a raciness problem (order of commits output changes,\n> which implies the original was expecting the time to increment between\n> two commits without running test_tick).\n\nAhh, ok, \"git commit && git commit\" without these environment\nvariable set and exported may or may not get the same timestamp from\nthe wallclock during the testing. With your patch, they are\nguaranteed to get the same timestamp. On the surface, it sounds\nlike a valid approach to smoke out any tests that rely on the\npassage of time, but realistically the machines are fast enough that\nit won't be a rare occasion for these two \"git commit\" invocations\nto be done within a single second, so I am not sure how much we\nwould be gaining. We _are_ getting more reproducible test\nenvironment, though, which may be a plus.\n"},{"id":"401157","messageId":"20200707214151.GA2300036@coredump.intra.peff.net","threadId":"53813","inReplyTo":"20200707205418.GB1396940@coredump.intra.peff.net","subject":"Re: [PATCH] Make some commit hashes in tests reproducible","fromName":"Jeff King","fromEmail":"peff@peff.net","sentAt":"2020-07-07T21:41:51Z","receivedAt":"2020-07-07T21:41:54Z","isPatch":true,"sender":{"key":"peff@peff.net","avatar":"https://avatars.githubusercontent.com/u/45925?v=4"},"body":"On Tue, Jul 07, 2020 at 04:54:18PM -0400, Jeff King wrote:\n\n> Note that the patch above does seem to cause two tests to fail. One of\n> them I _suspect_ is a raciness problem (order of commits output changes,\n> which implies the original was expecting the time to increment between\n> two commits without running test_tick).\n\nIt turns out this does depend on the system clock, but isn't racy in the\ntraditional sense. See the explanation below (which might be worth doing\neven if we don't switch to a deterministic time everywhere else).\n\n-- >8 --\nSubject: [PATCH] t6000: use test_tick consistently\n\nThe first two commits created in t6000 are done without test_tick,\nmeaning they use the current system clock. After that, we create one\nwith test_tick, which means it uses a deterministic time in the past.\n\nThe result of the \"symleft flag bit is propagated down from tag\" test\nrelies on the output order of commits from git-log, which in turn\ndepends on these timestamps. So this test is technically dependent on\nthe system clock time, though in practice it would only matter if your\nsystem clock was set before test_tick's default time (which is in 2005).\n\nHowever, let's use test_tick consistently for those early commits (and\nupdate the expected output to match). This makes the test deterministic,\nwhich is in turn easier to reason about and debug.\n\nNote that there's also a fourth commit here, and it does not use\ntest_tick. It does have a deterministic timestamp because of the prior\nuse of test_tick in the script, but it will always be the same time as\nthe third commit. Let's use test_tick here, too, for consistency. The\nmatching timestamps between the third and fourth commit are not an\nimportant part of the test.\n\nWe could also use test_commit in all of these cases, as it runs\ntest_tick under the hood. But it would be awkward to do so, as these\ntests diverge from the usual test_commit patterns (e.g., by creating\nmultiple files in a single commit).\n\nSigned-off-by: Jeff King \n---\n t/t6000-rev-list-misc.sh | 7 +++++--\n 1 file changed, 5 insertions(+), 2 deletions(-)\n\ndiff --git a/t/t6000-rev-list-misc.sh b/t/t6000-rev-list-misc.sh\nindex 3dc1ad8f71..3bb0e4ff8f 100755\n--- a/t/t6000-rev-list-misc.sh\n+++ b/t/t6000-rev-list-misc.sh\n@@ -8,6 +8,7 @@ test_expect_success setup '\n \techo content1 >wanted_file &&\n \techo content2 >unwanted_file &&\n \tgit add wanted_file unwanted_file &&\n+\ttest_tick &&\n \tgit commit -m one\n '\n \n@@ -21,6 +22,7 @@ test_expect_success 'rev-list --objects with pathspecs and deeper paths' '\n \tmkdir foo &&\n \t>foo/file &&\n \tgit add foo/file &&\n+\ttest_tick &&\n \tgit commit -m two &&\n \n \tgit rev-list --objects HEAD -- foo >output &&\n@@ -69,6 +71,7 @@ test_expect_success '--no-object-names and --object-names are last-one-wins' '\n '\n \n test_expect_success 'rev-list A..B and rev-list ^A B are the same' '\n+\ttest_tick &&\n \tgit commit --allow-empty -m another &&\n \tgit tag -a -m \"annotated\" v1.0 &&\n \tgit rev-list --objects ^v1.0^ v1.0 >expect &&\n@@ -84,10 +87,10 @@ test_expect_success 'propagate uninteresting flag down correctly' '\n test_expect_success 'symleft flag bit is propagated down from tag' '\n \tgit log --format=\"%m %s\" --left-right v1.0...master >actual &&\n \tcat >expect <<-\\EOF &&\n-\t> two\n-\t> one\n \t< another\n \t< that\n+\t> two\n+\t> one\n \tEOF\n \ttest_cmp expect actual\n '\n-- \n2.27.0.730.gcc195a083d\n\n"},{"id":"401158","messageId":"20200707215206.GA2300296@coredump.intra.peff.net","threadId":"53813","inReplyTo":"xmqq1rln3t4y.fsf@gitster.c.googlers.com","subject":"Re: [PATCH] Make some commit hashes in tests reproducible","fromName":"Jeff King","fromEmail":"peff@peff.net","sentAt":"2020-07-07T21:52:06Z","receivedAt":"2020-07-07T21:52:09Z","isPatch":true,"sender":{"key":"peff@peff.net","avatar":"https://avatars.githubusercontent.com/u/45925?v=4"},"body":"On Tue, Jul 07, 2020 at 02:35:57PM -0700, Junio C Hamano wrote:\n\n> Jeff King writes:\n> \n> > That's using the same start point as test_tick, though really it could\n> > be anything. I've intentionally _not_ called test_tick at the beginning\n> > of each script, because that would throw off all of the scripts that do\n> > use it by one tick (whereas the first test_tick will overwrite these\n> > values).\n> \n> Yup, I think that is a sensible approach.\n\nOK, I'll see if I can polish it into a series.\n\n> Another thing we could do is under DEVELOPER=YesPlease we can set\n> timestamps you just added here to some random time.\n> \n> The ones that do care about reproducibility guarantee by using\n> test_tick would not be affected, and those that were happy with the\n> current time should be happy with such a random timestamp. Or we\n> could just drop what this patch does only under DEVELOPER=YesPlease\n> which amounts to be the same as setting random time.\n\nThat should be easy to do. I wonder if it's really worth the trouble to\nmaintain two parallel worlds. I.e., one of the goals would be to stop\nworrying about this non-determinism. If we keep it as a requirement,\nthen we might as well do so all the time (and making it random under\nDEVELOPER is effectively keeping it as a requirement, since we expect\nall tests to pass under that flag).\n\nI'm also skeptical how often we use system times anyway, because _any_\nuse of test_commit or test_tick in a script is enough to make all of the\nsubsequent commands deterministic. I'd be more inclined to let a\nparticular script say \"I'm interested in random times\". But then, I'd\nthink such a script would be better written to trigger its interesting\ncases with a well-crafted set of deterministic times.\n\n-Peff\n"},{"id":"401166","messageId":"xmqqk0zf2bpl.fsf@gitster.c.googlers.com","threadId":"53813","inReplyTo":"20200707215206.GA2300296@coredump.intra.peff.net","subject":"Re: [PATCH] Make some commit hashes in tests reproducible","fromName":"Junio C Hamano","fromEmail":"gitster@pobox.com","sentAt":"2020-07-07T22:37:42Z","receivedAt":"2020-07-07T22:37:46Z","isPatch":true,"sender":{"key":"gitster@pobox.com","avatar":"https://avatars.githubusercontent.com/u/54884?v=4"},"body":"Jeff King writes:\n\n> I'm also skeptical how often we use system times anyway, because _any_\n> use of test_commit or test_tick in a script is enough to make all of the\n> subsequent commands deterministic. I'd be more inclined to let a\n> particular script say \"I'm interested in random times\". But then, I'd\n> think such a script would be better written to trigger its interesting\n> cases with a well-crafted set of deterministic times.\n\nYeah, the DEVELOPER=YesPlease was a tongue-in-cheek comment. \n\nReproducibility would mean we see less test breakages due to\nraciness, but I do not recall a case where digging into test\nbreakage due to raciness led to discovery of and fix to a real\nbreakage in Git itself, so it is probably a good thing.\n\nThanks.\n"},{"id":"401178","messageId":"CAFQ2z_PzBeubuhzPDJHG1VYbKhgLMaVdY1JMCfw1x8jOar10Wg@mail.gmail.com","threadId":"53813","inReplyTo":"xmqqfta33y0m.fsf@gitster.c.googlers.com","subject":"Re: [PATCH] Make some commit hashes in tests reproducible","fromName":"Han-Wen Nienhuys","fromEmail":"hanwen@google.com","sentAt":"2020-07-08T05:06:22Z","receivedAt":"2020-07-08T05:06:36Z","isPatch":true,"sender":{"key":"hanwen@google.com","avatar":"https://avatars.githubusercontent.com/u/31547?v=4"},"body":"On Tue, Jul 7, 2020 at 9:50 PM Junio C Hamano wrote:\n>\n> \"Han-Wen Nienhuys via GitGitGadget\" writes:\n>\n> > From: Han-Wen Nienhuys \n> >\n> > Adds test_tick to t5801-remote-helpers.sh and t3203-branch-output.sh\n>\n> That can be read from the patch. Also the subject tells us a half\n> of what you want to achieve with this change (by the way, your\n> subject is malformatted and lacks the : prefix; perhaps\n> \"[PATCH] tests: make commit object names reproducible\" or something),\n> but the readers are left hanging without knowing what motivated the\n> change. Do any test pieces in these scripts change their behaviour\n> based on what exact object names are assigned to them, making them\n> flaky and hard to test, and if so which one and in what way?\n\nYou're right, I forgot to provide a piece of the puzzle. These tests\nhave been failing either legitimately or flakily with reftable.\n\nI built a GIT_DEBUG_REFS functionality, which dumps ref backend\ninteractions onto stderr. This should be reworked to use the tracing\nfunctionality, but you can look at the patch in my reftable series.\n\nWhen a test fails with reftable, the easiest way to debug is running\nit both with and without GIT_DEBUG_REFS=1, and running a diff on the\noutput.\n\nThis needs the commit SHA1s to be deterministic, or the SHA1s will\ngenerate spurious diffs.\n\nI agree with Jeff, that a more structural approach to making sha1s\ndeterministic would be preferable.\n\n-- \nHan-Wen Nienhuys - Google Munich\nI work 80%. Don't expect answers from me on Fridays.\n--\nGoogle Germany GmbH, Erika-Mann-Strasse 33, 80636 Munich\nRegistergericht und -nummer: Hamburg, HRB 86891\nSitz der Gesellschaft: Hamburg\nGeschäftsführer: Paul Manicle, Halimah DeLaine Prado\n"}]}