{"thread":{"id":"56644","subject":"[PATCH] t/perf/perf-lib.sh: remove test_times.* at the end test_perf_()","startedAt":"2021-10-04T22:29:08Z","lastAt":"2021-10-13T21:09:12Z","messageCount":11,"participants":["Jeff Hostetler via GitGitGadget","Taylor Blau","Jeff King","Jeff Hostetler","Ævar Arnfjörð Bjarmason","Junio C Hamano","SZEDER Gábor"],"isPatch":true,"patchVersion":1,"patchTotal":null},"messages":[{"id":"437944","messageId":"pull.1051.git.1633386543759.gitgitgadget@gmail.com","threadId":"56644","inReplyTo":null,"subject":"[PATCH] t/perf/perf-lib.sh: remove test_times.* at the end test_perf_()","fromName":"Jeff Hostetler via GitGitGadget","fromEmail":"gitgitgadget@gmail.com","sentAt":"2021-10-04T22:29:03Z","receivedAt":"2021-10-04T22:29:08Z","isPatch":true,"sender":{"key":"git@jeffhostetler.com","avatar":null},"body":"From: Jeff Hostetler <jeffhost@microsoft.com>\n\nTeach test_perf_() to remove the temporary test_times.* files\nat the end of each test.\n\ntest_perf_() runs a particular GIT_PERF_REPEAT_COUNT times and creates\n./test_times.[123...].  It then uses a perl script to find the minimum\nover \"./test_times.*\" (note the wildcard) and writes that time to\n\"test-results/<testname>.<testnumber>.result\".\n\nIf the repeat count is changed during the pXXXX test script, stale\ntest_times.* files (from previous steps) may be included in the min()\ncomputation.  For example:\n\n...\nGIT_PERF_REPEAT_COUNT=3 \\\ntest_perf \"status\" \"\n\tgit status\n\"\n\nGIT_PERF_REPEAT_COUNT=1 \\\ntest_perf \"checkout other\" \"\n\tgit checkout other\n\"\n...\n\nThe time reported in the summary for \"XXXX.2 checkout other\" would\nbe \"min( checkout[1], status[2], status[3] )\".\n\nWe prevent that error by removing the test_times.* files at the end of\neach test.\n\nSigned-off-by: Jeff Hostetler <jeffhost@microsoft.com>\n---\n    t/perf/perf-lib.sh: remove test_times.* at the end test_perf_()\n    \n    Teach test_perf_() to remove the temporary test_times.* files at the end\n    of each test.\n    \n    test_perf_() runs a particular GIT_PERF_REPEAT_COUNT times and creates\n    ./test_times.[123...]. It then uses a perl script to find the minimum\n    over \"./test_times.*\" (note the wildcard) and writes that time to\n    \"test-results/..result\".\n    \n    If the repeat count is changed during the pXXXX test script, stale\n    test_times.* files (from previous steps) may be included in the min()\n    computation. For example:\n    \n    ... GIT_PERF_REPEAT_COUNT=3\n    test_perf \"status\" \" git status \"\n    \n    GIT_PERF_REPEAT_COUNT=1\n    test_perf \"checkout other\" \" git checkout other \" ...\n    \n    The time reported in the summary for \"XXXX.2 checkout other\" would be\n    \"min( checkout[1], status[2], status[3] )\".\n    \n    We prevent that error by removing the test_times.* files at the end of\n    each test.\n    \n    Signed-off-by: Jeff Hostetler jeffhost@microsoft.com\n\nPublished-As: https://github.com/gitgitgadget/git/releases/tag/pr-1051%2Fjeffhostetler%2Fperf-test-remove-test-times-v1\nFetch-It-Via: git fetch https://github.com/gitgitgadget/git pr-1051/jeffhostetler/perf-test-remove-test-times-v1\nPull-Request: https://github.com/gitgitgadget/git/pull/1051\n\n t/perf/perf-lib.sh | 1 +\n 1 file changed, 1 insertion(+)\n\ndiff --git a/t/perf/perf-lib.sh b/t/perf/perf-lib.sh\nindex f5ed092ee59..a1b5d2804dc 100644\n--- a/t/perf/perf-lib.sh\n+++ b/t/perf/perf-lib.sh\n@@ -230,6 +230,7 @@ test_perf_ () {\n \t\ttest_ok_ \"$1\"\n \tfi\n \t\"$TEST_DIRECTORY\"/perf/min_time.perl test_time.* >\"$base\".result\n+\trm test_time.*\n }\n \n test_perf () {\n\nbase-commit: 0785eb769886ae81e346df10e88bc49ffc0ac64e\n-- \ngitgitgadget\n"},{"id":"437992","messageId":"YVyPH59LpxFLHep0@nand.local","threadId":"56644","inReplyTo":"pull.1051.git.1633386543759.gitgitgadget@gmail.com","subject":"Re: [PATCH] t/perf/perf-lib.sh: remove test_times.* at the end test_perf_()","fromName":"Taylor Blau","fromEmail":"me@ttaylorr.com","sentAt":"2021-10-05T17:45:03Z","receivedAt":"2021-10-05T17:49:03Z","isPatch":true,"sender":{"key":"me@ttaylorr.com","avatar":"https://avatars.githubusercontent.com/u/301000140?v=4"},"body":"On Mon, Oct 04, 2021 at 10:29:03PM +0000, Jeff Hostetler via GitGitGadget wrote:\n> From: Jeff Hostetler <jeffhost@microsoft.com>\n>\n> Teach test_perf_() to remove the temporary test_times.* files\n\nSmall nit: s/test_times/test_time here and throughout.\n\n> at the end of each test.\n>\n> test_perf_() runs a particular GIT_PERF_REPEAT_COUNT times and creates\n> ./test_times.[123...].  It then uses a perl script to find the minimum\n> over \"./test_times.*\" (note the wildcard) and writes that time to\n> \"test-results/<testname>.<testnumber>.result\".\n>\n> If the repeat count is changed during the pXXXX test script, stale\n> test_times.* files (from previous steps) may be included in the min()\n> computation.  For example:\n>\n> ...\n> GIT_PERF_REPEAT_COUNT=3 \\\n> test_perf \"status\" \"\n> \tgit status\n> \"\n>\n> GIT_PERF_REPEAT_COUNT=1 \\\n> test_perf \"checkout other\" \"\n> \tgit checkout other\n> \"\n> ...\n>\n> The time reported in the summary for \"XXXX.2 checkout other\" would\n> be \"min( checkout[1], status[2], status[3] )\".\n>\n> We prevent that error by removing the test_times.* files at the end of\n> each test.\n\nWell explained, and makes sense to me. I didn't know we set\nGIT_PERF_REPEAT_COUNT inline with the performance tests themselves, but\ngrepping shows that we do it in the fsmonitor tests.\n\nDropping any test_times files makes sense as the right thing to do. I\nhave no opinion on whether it should happen before running a perf test,\nor after generating the results. So what you did here looks good to me.\n\nAn alternative approach might be to only read the test_time.n files we\nknow should exist based on GIT_PERF_REPEAT_COUNT, perhaps like:\n\n    test_seq \"$GIT_PERF_REPEAT_COUNT\" | perl -lne 'print \"test_time.$_\"' |\n    xargs \"$TEST_DIRECTORY/perf/min_time.perl\" >\"$base\".result\n\nbut I'm not convinced that the above is at all better than what you\nwrote, since leaving the extra files around is the footgun we're trying\nto avoid in the first place.\n\nThanks,\nTaylor\n"},{"id":"438088","messageId":"YV3314Dnhj7srFZ4@coredump.intra.peff.net","threadId":"56644","inReplyTo":"YVyPH59LpxFLHep0@nand.local","subject":"Re: [PATCH] t/perf/perf-lib.sh: remove test_times.* at the end test_perf_()","fromName":"Jeff King","fromEmail":"peff@peff.net","sentAt":"2021-10-06T19:24:07Z","receivedAt":"2021-10-06T19:24:09Z","isPatch":true,"sender":{"key":"peff@peff.net","avatar":"https://avatars.githubusercontent.com/u/45925?v=4"},"body":"On Tue, Oct 05, 2021 at 01:45:03PM -0400, Taylor Blau wrote:\n\n> > GIT_PERF_REPEAT_COUNT=3 \\\n> > test_perf \"status\" \"\n> > \tgit status\n> > \"\n> >\n> > GIT_PERF_REPEAT_COUNT=1 \\\n> > test_perf \"checkout other\" \"\n> > \tgit checkout other\n> > \"\n> [...]\n> \n> Well explained, and makes sense to me. I didn't know we set\n> GIT_PERF_REPEAT_COUNT inline with the performance tests themselves, but\n> grepping shows that we do it in the fsmonitor tests.\n\nNeither did I. IMHO that is a hack that we would do better to avoid, as\nthe point of it is to let the user drive the decision of time versus\nquality of results. So the first example above is spending extra time\nthat the user may have asked us not to, and the second is getting less\nsignificant results by not repeating the trial.\n\nPresumably the issue in the second one is that the test modifies state.\nThe \"right\" solution there is to give test_perf() a way to set up the\nstate between trials (you can do it in the test_perf block, but you'd\nwant to avoid letting the setup step affect the timing).\n\nI'd also note that\n\n  GIT_PERF_REPEAT_COUNT=1 \\\n  test_perf ...\n\nin the commit message is a bad pattern. On some shells, the one-shot\nvariable before a function will persist after the function returns (so\nit would accidentally tweak the count for later tests, too).\n\nAll that said, I do think cleaning up the test_time files after each\ntest_perf is a good precuation, even if I don't think it's a good idea\nin general to flip the REPEAT_COUNT variable in the middle of a test.\n\n-Peff\n"},{"id":"438089","messageId":"YV34ZJXqF6KtpNM1@nand.local","threadId":"56644","inReplyTo":"YV3314Dnhj7srFZ4@coredump.intra.peff.net","subject":"Re: [PATCH] t/perf/perf-lib.sh: remove test_times.* at the end test_perf_()","fromName":"Taylor Blau","fromEmail":"me@ttaylorr.com","sentAt":"2021-10-06T19:26:28Z","receivedAt":"2021-10-06T19:26:32Z","isPatch":true,"sender":{"key":"me@ttaylorr.com","avatar":"https://avatars.githubusercontent.com/u/301000140?v=4"},"body":"On Wed, Oct 06, 2021 at 03:24:07PM -0400, Jeff King wrote:\n> All that said, I do think cleaning up the test_time files after each\n> test_perf is a good precuation, even if I don't think it's a good idea\n> in general to flip the REPEAT_COUNT variable in the middle of a test.\n\nThanks for putting it so concisely, I couldn't agree more.\n\nThanks,\nTaylor\n"},{"id":"438183","messageId":"3f03ed89-d3db-32ba-3c1f-b8fac7cfb097@jeffhostetler.com","threadId":"56644","inReplyTo":"YV3314Dnhj7srFZ4@coredump.intra.peff.net","subject":"Re: [PATCH] t/perf/perf-lib.sh: remove test_times.* at the end test_perf_()","fromName":"Jeff Hostetler","fromEmail":"git@jeffhostetler.com","sentAt":"2021-10-07T17:49:15Z","receivedAt":"2021-10-07T17:49:18Z","isPatch":true,"sender":{"key":"git@jeffhostetler.com","avatar":null},"body":"\n\nOn 10/6/21 3:24 PM, Jeff King wrote:\n> On Tue, Oct 05, 2021 at 01:45:03PM -0400, Taylor Blau wrote:\n> \n>>> GIT_PERF_REPEAT_COUNT=3 \\\n>>> test_perf \"status\" \"\n>>> \tgit status\n>>> \"\n>>>\n>>> GIT_PERF_REPEAT_COUNT=1 \\\n>>> test_perf \"checkout other\" \"\n>>> \tgit checkout other\n>>> \"\n>> [...]\n>>\n>> Well explained, and makes sense to me. I didn't know we set\n>> GIT_PERF_REPEAT_COUNT inline with the performance tests themselves, but\n>> grepping shows that we do it in the fsmonitor tests.\n> \n> Neither did I. IMHO that is a hack that we would do better to avoid, as\n> the point of it is to let the user drive the decision of time versus\n> quality of results. So the first example above is spending extra time\n> that the user may have asked us not to, and the second is getting less\n> significant results by not repeating the trial.\n> \n> Presumably the issue in the second one is that the test modifies state.\n> The \"right\" solution there is to give test_perf() a way to set up the\n> state between trials (you can do it in the test_perf block, but you'd\n> want to avoid letting the setup step affect the timing).\n> \n> I'd also note that\n> \n>    GIT_PERF_REPEAT_COUNT=1 \\\n>    test_perf ...\n> \n> in the commit message is a bad pattern. On some shells, the one-shot\n> variable before a function will persist after the function returns (so\n> it would accidentally tweak the count for later tests, too).\n> \n> All that said, I do think cleaning up the test_time files after each\n> test_perf is a good precuation, even if I don't think it's a good idea\n> in general to flip the REPEAT_COUNT variable in the middle of a test.\n> \n> -Peff\n> \n\nYeah, I don't think I want to keep switching the value of _REPEAT_COUNT\nin the body of the test.  (It did feel a little \"against the spirit\" of\nthe framework.)  I'm in the process of redoing the test to not need\nthat.\n\n\n\nThere's a problem with the perf test assumptions here and I'm curious\nif there's a better way to use the perf-lib that I'm not thinking of.\n\nWhen working with big repos (in this case 100K files), the actual\ncheckout takes 33 seconds, but the repetitions are fast -- since they\njust print a warning and stop.  In the 1M file case that number is ~7\nminutes for the first instance.)  With the code in min_time.perl\nsilently taking the min() of the runs, it looks like the checkout was\nreally fast when it wasn't.  That fact gets hidden in the summary report\nprinted at the end.\n\n$ time ~/work/core/git checkout p0006-ballast\nUpdating files: 100% (100000/100000), done.\nSwitched to branch 'p0006-ballast'\n\nreal\t0m33.510s\nuser\t0m2.757s\nsys\t0m15.565s\n\n$ time ~/work/core/git checkout p0006-ballast\nAlready on 'p0006-ballast'\n\nreal\t0m0.745s\nuser\t0m0.214s\nsys\t0m4.705s\n\n$ time ~/work/core/git checkout p0006-ballast\nAlready on 'p0006-ballast'\n\nreal\t0m0.738s\nuser\t0m0.134s\nsys\t0m6.850s\n\n\nI could use test_expect_success() for anything that does want\nto change state, and then save test_perf() for status calls\nand other read-only tests, but I think we lose some opportunities\nhere.\n\nI'm open to suggestions here.\n\nThanks,\nJeff\n\n"},{"id":"438255","messageId":"YV+zFqi4VmBVJYex@coredump.intra.peff.net","threadId":"56644","inReplyTo":"3f03ed89-d3db-32ba-3c1f-b8fac7cfb097@jeffhostetler.com","subject":"Re: [PATCH] t/perf/perf-lib.sh: remove test_times.* at the end test_perf_()","fromName":"Jeff King","fromEmail":"peff@peff.net","sentAt":"2021-10-08T02:55:18Z","receivedAt":"2021-10-08T02:55:21Z","isPatch":true,"sender":{"key":"peff@peff.net","avatar":"https://avatars.githubusercontent.com/u/45925?v=4"},"body":"On Thu, Oct 07, 2021 at 01:49:15PM -0400, Jeff Hostetler wrote:\n\n> Yeah, I don't think I want to keep switching the value of _REPEAT_COUNT\n> in the body of the test.  (It did feel a little \"against the spirit\" of\n> the framework.)  I'm in the process of redoing the test to not need\n> that.\n\nSounds good to me. :)\n\n> There's a problem with the perf test assumptions here and I'm curious\n> if there's a better way to use the perf-lib that I'm not thinking of.\n> \n> When working with big repos (in this case 100K files), the actual\n> checkout takes 33 seconds, but the repetitions are fast -- since they\n> just print a warning and stop.  In the 1M file case that number is ~7\n> minutes for the first instance.)  With the code in min_time.perl\n> silently taking the min() of the runs, it looks like the checkout was\n> really fast when it wasn't.  That fact gets hidden in the summary report\n> printed at the end.\n\nRight. So your option now is basically something like:\n\n  test_perf 'checkout' '\n\tgit reset --hard the_original_state &&\n\tgit checkout\n  '\n\nI.e., reset the state _and_ perform the operation you want to time,\nwithin a single test_perf(). (Here it's a literal \"git reset\", but\nobviously it could be anything to adjust the state back to the\nbaseline). But that reset operation will get lumped into your timing.\nThat might not matter if it's comparatively cheap, but it might throw\noff all your results.\n\nWhat I'd propose instead is that we ought to have:\n\n  test_perf 'checkout'\n            --prepare '\n\t        git reset --hard the_original_state\n\t    ' '\n\t        git checkout\n\t    '\n\nHaving two multi-line snippets is a bit ugly (check out that awful\nmiddle line), but I think this could be added without breaking existing\ntests (they just wouldn't have a --prepare option).\n\nIf that syntax is too horrendous, we could have:\n\n  # this saves the snippet in a variable internally, and runs\n  # it before each trial of the next test_perf(), after which\n  # it is discarded\n  test_perf_prepare '\n          git reset --hard the_original_state\n  '\n\n  test_perf 'checkout' '\n          git checkout\n  '\n\nI think that would be pretty easy to implement, and would solve the most\ncommon form of this problem. And there's plenty of prior art; just about\nevery decent benchmarking system has a \"do this before each trial\"\nmechanism. Our t/perf suite (as you probably noticed) is rather more\nad-hoc and less mature.\n\nThere are cases it doesn't help, though. For instance, in one of the\nscripts we measure the time to run \"git repack -adb\" to generate\nbitmaps. But the first run has to do more work, because we can reuse\nresults for subsequent ones! It would help to \"rm -f\nobjects/pack/*.bitmap\", but even that's not entirely fair, as it will be\nrepacking from a single pack, versus whatever state we started with.\n\nAnd there I think the whole \"take the best run\" strategy is hampering\nus. These inaccuracies in our timings go unseen, because we don't do any\nstatistical analysis of the results. Whereas a tool like hyperfine (for\nexample) will run trials until the mean stabilizes, and then let you\nknow when there were trials outside of a standard deviation.\n\nI know we're hesitant to introduce dependencies, but I do wonder if we\ncould have much higher quality perf results if we accepted a dependency\non a tool like that. I'd never want that for the regular test suite, but\nI'd my feelings for the perf suite are much looser. I suspect not many\npeople run it at all, and its main utility is showing off improvements\nand looking for broad regressions. It's possible somebody would want to\ntrack down a performance change on a specific obscure platform, but in\ngeneral I'd suspect they'd be much better off timing things manually in\nsuch a case.\n\nSo there. That was probably more than you wanted to hear, and further\nthan you want to go right now. In the near-term for the tests you're\ninterested in, something like the \"prepare\" feature I outlined above\nwould probably not be too hard to add, and would address your immediate\nproblem.\n\n-Peff\n"},{"id":"438280","messageId":"87pmsgeytx.fsf@evledraar.gmail.com","threadId":"56644","inReplyTo":"YV+zFqi4VmBVJYex@coredump.intra.peff.net","subject":"A hard dependency on \"hyperfine\" for t/perf","fromName":"Ævar Arnfjörð Bjarmason","fromEmail":"avarab@gmail.com","sentAt":"2021-10-08T07:47:58Z","receivedAt":"2021-10-08T07:54:24Z","isPatch":false,"sender":{"key":"avarab@gmail.com","avatar":"https://avatars.githubusercontent.com/u/45301?v=4"},"body":"\nOn Thu, Oct 07 2021, Jeff King wrote:\n\n> And there I think the whole \"take the best run\" strategy is hampering\n> us. These inaccuracies in our timings go unseen, because we don't do any\n> statistical analysis of the results. Whereas a tool like hyperfine (for\n> example) will run trials until the mean stabilizes, and then let you\n> know when there were trials outside of a standard deviation.\n>\n> I know we're hesitant to introduce dependencies, but I do wonder if we\n> could have much higher quality perf results if we accepted a dependency\n> on a tool like that. I'd never want that for the regular test suite, but\n> I'd my feelings for the perf suite are much looser. I suspect not many\n> people run it at all, and its main utility is showing off improvements\n> and looking for broad regressions. It's possible somebody would want to\n> track down a performance change on a specific obscure platform, but in\n> general I'd suspect they'd be much better off timing things manually in\n> such a case.\n>\n> So there. That was probably more than you wanted to hear, and further\n> than you want to go right now. In the near-term for the tests you're\n> interested in, something like the \"prepare\" feature I outlined above\n> would probably not be too hard to add, and would address your immediate\n> problem.\n\nI'd really like that, as you point out the statistics in t/perf now are\nquite bad.\n\nA tool like hyperfine is ultimately generalized (for the purposes of the\ntest suite) as something that can run templated code with labels. If\nanyone cared I don't see why we couldn't ship a hyperfine-fallback.pl or\nwhatever that accepted the same parameters, and ran our current (and\nworse) end-to-end statistics.\n\nIf that is something you're encouraged to work on and are taking\nrequests :) : It would be really nice if t/perf could say emit a one-off\nMakefile and run the tests via that, rather than the one-off nproc=1\n./run script we've got now.\n\nWith the same sort of templating a \"hyperfine\" invocation would need\n(and some prep/teardown phases) it would make it easy to run perf tests\nin parallel with ncores, or even across N number of machines.\n"},{"id":"438300","messageId":"xmqqee8vl90e.fsf@gitster.g","threadId":"56644","inReplyTo":"YV+zFqi4VmBVJYex@coredump.intra.peff.net","subject":"Re: [PATCH] t/perf/perf-lib.sh: remove test_times.* at the end test_perf_()","fromName":"Junio C Hamano","fromEmail":"gitster@pobox.com","sentAt":"2021-10-08T17:30:09Z","receivedAt":"2021-10-08T17:30:14Z","isPatch":true,"sender":{"key":"gitster@pobox.com","avatar":"https://avatars.githubusercontent.com/u/54884?v=4"},"body":"Jeff King <peff@peff.net> writes:\n\n> What I'd propose instead is that we ought to have:\n>\n>   test_perf 'checkout'\n>             --prepare '\n> \t        git reset --hard the_original_state\n> \t    ' '\n> \t        git checkout\n> \t    '\n>\n> Having two multi-line snippets is a bit ugly (check out that awful\n> middle line), but I think this could be added without breaking existing\n> tests (they just wouldn't have a --prepare option).\n>\n> If that syntax is too horrendous, we could have:\n>\n>   # this saves the snippet in a variable internally, and runs\n>   # it before each trial of the next test_perf(), after which\n>   # it is discarded\n>   test_perf_prepare '\n>           git reset --hard the_original_state\n>   '\n>\n>   test_perf 'checkout' '\n>           git checkout\n>   '\n>\n> I think that would be pretty easy to implement, and would solve the most\n> common form of this problem. And there's plenty of prior art; just about\n> every decent benchmarking system has a \"do this before each trial\"\n> mechanism. Our t/perf suite (as you probably noticed) is rather more\n> ad-hoc and less mature.\n\nNice.\n\n> There are cases it doesn't help, though. For instance, in one of the\n> scripts we measure the time to run \"git repack -adb\" to generate\n> bitmaps. But the first run has to do more work, because we can reuse\n> results for subsequent ones! It would help to \"rm -f\n> objects/pack/*.bitmap\", but even that's not entirely fair, as it will be\n> repacking from a single pack, versus whatever state we started with.\n\nYou need a \"do this too for each iteration but do not time it\", i.e.\n\n    test_perf 'repack performance' --prepare '\n\tmake a messy original repository\n    ' --per-iteration-prepare '\n\tprepare a test repository from the messy original\n    ' --time-this-part-only '\n        git repack -adb\n    '\n\nSyntactically, eh, Yuck.\n\n"},{"id":"438334","messageId":"YWCilnNa2eAakoX0@coredump.intra.peff.net","threadId":"56644","inReplyTo":"xmqqee8vl90e.fsf@gitster.g","subject":"Re: [PATCH] t/perf/perf-lib.sh: remove test_times.* at the end test_perf_()","fromName":"Jeff King","fromEmail":"peff@peff.net","sentAt":"2021-10-08T19:57:10Z","receivedAt":"2021-10-08T19:57:16Z","isPatch":true,"sender":{"key":"peff@peff.net","avatar":"https://avatars.githubusercontent.com/u/45925?v=4"},"body":"On Fri, Oct 08, 2021 at 10:30:09AM -0700, Junio C Hamano wrote:\n\n> > There are cases it doesn't help, though. For instance, in one of the\n> > scripts we measure the time to run \"git repack -adb\" to generate\n> > bitmaps. But the first run has to do more work, because we can reuse\n> > results for subsequent ones! It would help to \"rm -f\n> > objects/pack/*.bitmap\", but even that's not entirely fair, as it will be\n> > repacking from a single pack, versus whatever state we started with.\n> \n> You need a \"do this too for each iteration but do not time it\", i.e.\n> \n>     test_perf 'repack performance' --prepare '\n> \tmake a messy original repository\n>     ' --per-iteration-prepare '\n> \tprepare a test repository from the messy original\n>     ' --time-this-part-only '\n>         git repack -adb\n>     '\n> \n> Syntactically, eh, Yuck.\n\nIf any step doesn't need to be per-iteration, you can do it in a\nseparate test_expect_success block. So --prepare would always be\nper-iteration, I think.\n\nThe tricky thing I meant to highlight in that example is that the\npreparation step is non-obvious, since the timed command actually throws\naway the original state. But we can probably stash away what we need.\nWith the test_perf_prepare I showed earlier, maybe:\n\n  test_expect_success 'stash original state' '\n\tcp -al objects objects.orig\n  '\n\n  test_perf_prepare 'set up original state' '\n\trm -rf objects &&\n\tcp -al objects.orig objects\n  '\n\n  test_perf 'repack' '\n\tgit repack -adb\n  '\n\nwhich is not too bad. Of course it is made a lot easier by my use of the\nunportable \"cp -l\", but you get the general idea. ;) This is all a rough\nsketch anyway, and not something I plan on working on anytime soon.\n\nFor Jeff's case, the preparation would hopefully just be some sequence\nof reset/read-tree/etc to manipulate the index and working tree to the\noriginal state.\n\n-Peff\n"},{"id":"438428","messageId":"20211010212626.GB571180@szeder.dev","threadId":"56644","inReplyTo":"YVyPH59LpxFLHep0@nand.local","subject":"Re: [PATCH] t/perf/perf-lib.sh: remove test_times.* at the end test_perf_()","fromName":"SZEDER Gábor","fromEmail":"szeder.dev@gmail.com","sentAt":"2021-10-10T21:26:26Z","receivedAt":"2021-10-10T21:26:32Z","isPatch":true,"sender":{"key":"szeder.dev@gmail.com","avatar":"https://avatars.githubusercontent.com/u/116324?v=4"},"body":"On Tue, Oct 05, 2021 at 01:45:03PM -0400, Taylor Blau wrote:\n> On Mon, Oct 04, 2021 at 10:29:03PM +0000, Jeff Hostetler via GitGitGadget wrote:\n> > From: Jeff Hostetler <jeffhost@microsoft.com>\n> >\n> > Teach test_perf_() to remove the temporary test_times.* files\n> \n> Small nit: s/test_times/test_time here and throughout.\n> \n> > at the end of each test.\n> >\n> > test_perf_() runs a particular GIT_PERF_REPEAT_COUNT times and creates\n> > ./test_times.[123...].  It then uses a perl script to find the minimum\n> > over \"./test_times.*\" (note the wildcard) and writes that time to\n> > \"test-results/<testname>.<testnumber>.result\".\n> >\n> > If the repeat count is changed during the pXXXX test script, stale\n> > test_times.* files (from previous steps) may be included in the min()\n> > computation.  For example:\n> >\n> > ...\n> > GIT_PERF_REPEAT_COUNT=3 \\\n> > test_perf \"status\" \"\n> > \tgit status\n> > \"\n> >\n> > GIT_PERF_REPEAT_COUNT=1 \\\n> > test_perf \"checkout other\" \"\n> > \tgit checkout other\n> > \"\n> > ...\n> >\n> > The time reported in the summary for \"XXXX.2 checkout other\" would\n> > be \"min( checkout[1], status[2], status[3] )\".\n> >\n> > We prevent that error by removing the test_times.* files at the end of\n> > each test.\n> \n> Well explained, and makes sense to me. I didn't know we set\n> GIT_PERF_REPEAT_COUNT inline with the performance tests themselves, but\n> grepping shows that we do it in the fsmonitor tests.\n> \n> Dropping any test_times files makes sense as the right thing to do. I\n> have no opinion on whether it should happen before running a perf test,\n> or after generating the results. So what you did here looks good to me.\n\nI think it's better to remove those files before running the perf\ntest, and leave them behind after the test finished.  This would give\ndevelopers an opportunity to use the timing results for whatever other\nstatistics they might be interested in.\n\nAnd yes, I think it would be better if 'make test' left behind\n't/test-results' with all the test trace output for later analysis as\nwell.  E.g. grepping through the test logs can uncover bugs like this:\n\n  https://public-inbox.org/git/20211010172809.1472914-1-szeder.dev@gmail.com/\n\nand I've fixed several similar test bugs that I've found when looking\nthrough 'test-results/*.out'.  Alas, it's always a bit of a hassle to\ncomment out 'make clean-except-prove-cache' in 't/Makefile'.\n\n"},{"id":"438698","messageId":"568aa754-4ff2-1841-afaf-519673e36bcc@jeffhostetler.com","threadId":"56644","inReplyTo":"20211010212626.GB571180@szeder.dev","subject":"Re: [PATCH] t/perf/perf-lib.sh: remove test_times.* at the end test_perf_()","fromName":"Jeff Hostetler","fromEmail":"git@jeffhostetler.com","sentAt":"2021-10-13T21:09:06Z","receivedAt":"2021-10-13T21:09:12Z","isPatch":true,"sender":{"key":"git@jeffhostetler.com","avatar":null},"body":"\n\nOn 10/10/21 5:26 PM, SZEDER Gábor wrote:\n> On Tue, Oct 05, 2021 at 01:45:03PM -0400, Taylor Blau wrote:\n>> On Mon, Oct 04, 2021 at 10:29:03PM +0000, Jeff Hostetler via GitGitGadget wrote:\n>>> From: Jeff Hostetler <jeffhost@microsoft.com>\n>>>\n>>> Teach test_perf_() to remove the temporary test_times.* files\n>>\n>> Small nit: s/test_times/test_time here and throughout.\n>>\n>>> at the end of each test.\n>>>\n>>> test_perf_() runs a particular GIT_PERF_REPEAT_COUNT times and creates\n>>> ./test_times.[123...].  It then uses a perl script to find the minimum\n>>> over \"./test_times.*\" (note the wildcard) and writes that time to\n>>> \"test-results/<testname>.<testnumber>.result\".\n>>>\n>>> If the repeat count is changed during the pXXXX test script, stale\n>>> test_times.* files (from previous steps) may be included in the min()\n>>> computation.  For example:\n>>>\n>>> ...\n>>> GIT_PERF_REPEAT_COUNT=3 \\\n>>> test_perf \"status\" \"\n>>> \tgit status\n>>> \"\n>>>\n>>> GIT_PERF_REPEAT_COUNT=1 \\\n>>> test_perf \"checkout other\" \"\n>>> \tgit checkout other\n>>> \"\n>>> ...\n>>>\n>>> The time reported in the summary for \"XXXX.2 checkout other\" would\n>>> be \"min( checkout[1], status[2], status[3] )\".\n>>>\n>>> We prevent that error by removing the test_times.* files at the end of\n>>> each test.\n>>\n>> Well explained, and makes sense to me. I didn't know we set\n>> GIT_PERF_REPEAT_COUNT inline with the performance tests themselves, but\n>> grepping shows that we do it in the fsmonitor tests.\n>>\n>> Dropping any test_times files makes sense as the right thing to do. I\n>> have no opinion on whether it should happen before running a perf test,\n>> or after generating the results. So what you did here looks good to me.\n> \n> I think it's better to remove those files before running the perf\n> test, and leave them behind after the test finished.  This would give\n> developers an opportunity to use the timing results for whatever other\n> statistics they might be interested in.\n\nI could see doing it before.  I'd like to leave it as is for now.\nLet's fix the correctness now and we can fine tune it later (with\nyour suggestion below).\n\nThat makes me wonder if it would it be better to have the script\nkeep all of the test time values?  That is, create something like\ntest_time.$test_count.$test_seq.  Then you could look at all of\nthe timings over the whole test script, rather just of those of the\none where you stopped it.\n\n\n> \n> And yes, I think it would be better if 'make test' left behind\n> 't/test-results' with all the test trace output for later analysis as\n> well.  E.g. grepping through the test logs can uncover bugs like this:\n> \n>    https://public-inbox.org/git/20211010172809.1472914-1-szeder.dev@gmail.com/\n> \n> and I've fixed several similar test bugs that I've found when looking\n> through 'test-results/*.out'.  Alas, it's always a bit of a hassle to\n> comment out 'make clean-except-prove-cache' in 't/Makefile'.\n> \n\nJeff\n"}]}