{"thread":{"id":"44329","subject":"Drastic jump in the time required for the test suite","startedAt":"2016-10-19T15:47:22Z","lastAt":"2016-10-28T06:39:09Z","messageCount":31,"participants":["Johannes Schindelin","Junio C Hamano","Jeff King","Duy Nguyen","Stefan Beller","René Scharfe","Matthieu Moy","Johannes Sixt","Dennis Kaarsemaker","Eric Wong"],"isPatch":false,"patchVersion":null,"patchTotal":null},"messages":[{"id":"304397","messageId":"alpine.DEB.2.20.1610191049040.3847@virtualbox","threadId":"44329","inReplyTo":null,"subject":"Drastic jump in the time required for the test suite","fromName":"Johannes Schindelin","fromEmail":"johannes.schindelin@gmx.de","sentAt":"2016-10-19T09:18:19Z","receivedAt":"2016-10-19T15:47:22Z","isPatch":false,"sender":{"key":"johannes.schindelin@gmx.de","avatar":"https://avatars.githubusercontent.com/u/127790?v=4"},"body":"Hi Junio,\n\nI know you are a fan of testing things thoroughly in the test suite, but I\nhave to say that it is getting out of hand, in particular due to our\nover-use of shell script idioms (which really only run fast on Linux, not\na good idea for a portable software).\n\nMy builds of `pu` now time out, after running for 3h straight in the VM\ndedicated to perform the daily routine of building and testing the git.git\nbranches in Git for Windows' SDK. For comparison, `next` passes build &\ntests in 2.6h. That is quite the jump.\n\nUnfortunately, I cannot tell you precisely when this massive increase\nhappened (we are talking about half an hour, after all), because there\nwere build failures preventing the test from being run for the last 40\ndays (and my build job only retains the results for 7 days currently,\nanyway, in addition to the last successful/unsuccessful build).\n\nWhat I can say for certain is that the version from 41 days ago (commit\n7837d4a) ran for only 2.6h, just as `next` does today, and passed without\nfailure.\n\nEvery single revision of `pu` since then has been broken in one way or\nanother. Mostly already the build, so that the tests would not even start\nto run.\n\nWhat I can also say for certain is that the version from yesterday (commit\n4ef44ce) was the first one in a week that built successfully and hence\nreached the test phase, and it was the first version of `pu` ever to time\nout after running for 3h.\n\nI will increase the time-out, of course, but we are walking into a\ndangerous territory here: the build & test requires such an incredibly\nlong time now that the VM will start to take more than 24h to complete all\n8 tasks (building & testing the `pu`, `next`, `master` and `maint`\nbranches, as well as trying to rebase Git for Windows' patches onto each\nof them).\n\nAs those tasks are scheduled to run once every 24h, I will no longer be\nable to notify you and the mailing list in a timely manner, if at all,\nbecause the queue will clog up.\n\nMaybe we should start optimizing the tests to become more useful again, by\nforcing them not to take such an insane amount of time?\n\nCiao,\nDscho\n"},{"id":"304403","messageId":"xmqqbmygmehv.fsf@gitster.mtv.corp.google.com","threadId":"44329","inReplyTo":"alpine.DEB.2.20.1610191049040.3847@virtualbox","subject":"Re: Drastic jump in the time required for the test suite","fromName":"Junio C Hamano","fromEmail":"gitster@pobox.com","sentAt":"2016-10-19T17:32:12Z","receivedAt":"2016-10-19T17:32:21Z","isPatch":false,"sender":{"key":"gitster@pobox.com","avatar":"https://avatars.githubusercontent.com/u/54884?v=4"},"body":"Johannes Schindelin writes:\n\n> What I can also say for certain is that the version from yesterday (commit\n> 4ef44ce) was the first one in a week that built successfully and hence\n> reached the test phase, and it was the first version of `pu` ever to time\n> out after running for 3h.\n\nI am sympathetic, but I'd be lying if I said I can feel your pain.\n\nAdmittedly I do not run _all_ the tests (I certainly know that I\nexclude the ones behind EXPENSIVE prerequisite), but after every\nrebuilding of 'jch' and 'pu', I run the testsuite (and also rebuild\ndocs) before pushing them out, and \"make test && make doc && make\ninstall install-doc\" run sequentially for the four integration\nbranches finishes within 15 minutes, even when I run them after\n\"make clean\".\n\nPerhaps the recent change to run the tests in parallel from slower\nto faster under prove may be helping my case.\n\n> Maybe we should start optimizing the tests...\n\nYup, two things that come to mind are to identify long ones and see\nif each of them can be split into two halves that can be run in\nparallel, and to go through the tests with fine toothed comb and\nremove the ones that test exactly the same thing as another test.\nThe latter would be very time consuming, though.\n"},{"id":"304420","messageId":"20161019205638.m3ytxozzmeh47ml2@sigill.intra.peff.net","threadId":"44329","inReplyTo":"xmqqbmygmehv.fsf@gitster.mtv.corp.google.com","subject":"Re: Drastic jump in the time required for the test suite","fromName":"Jeff King","fromEmail":"peff@peff.net","sentAt":"2016-10-19T20:56:39Z","receivedAt":"2016-10-19T20:56:46Z","isPatch":false,"sender":{"key":"peff@peff.net","avatar":"https://avatars.githubusercontent.com/u/45925?v=4"},"body":"On Wed, Oct 19, 2016 at 10:32:12AM -0700, Junio C Hamano wrote:\n\n> > Maybe we should start optimizing the tests...\n> \n> Yup, two things that come to mind are to identify long ones and see\n> if each of them can be split into two halves that can be run in\n> parallel, and to go through the tests with fine toothed comb and\n> remove the ones that test exactly the same thing as another test.\n> The latter would be very time consuming, though.\n\nFWIW, I have made attempts at \"split long ones into two\" before, and\ndidn't come up with much. There _are_ some tests that are much longer\nthan others[1], but they are not longer than the whole suite takes to\nrun. So running in slow-to-fast order means they start first, are run in\nparallel with the other tests, and the CPUs stay relatively full through\nthe whole run.\n\nOf course YMMV; the long tests on Windows may be different, or\nproportionally much longer (I note the worst cases almost all involve\nrebase, which as a shell script is presumably worse on Windows than\nelsewhere). And of course any reasoning about slow-to-fast order does\nnot apply if you are not using a tool to do that for you. :)\n\n-Peff\n\n[1] After running \"make prove\" (time are in seconds):\n\n $ perl -MYAML -e '\n $_ = do { local $/; <> };\n # prove puts this non-YAML cruft at the end\n s/\\.\\.\\.$//s;\n\n my $t = YAML::Load($_)->{tests};\n print \"$_->[1] $_->[0]\\n\" for\n sort { $b->[1] <=> $a->[1] }\n map { [$_, $t->{$_}->{elapsed}] }\n keys(%$t);\n ' .prove | head\n\n 43.216765165329 t3404-rebase-interactive.sh\n 30.6568658351898 t3421-rebase-topology-linear.sh\n 27.92564702034 t9001-send-email.sh\n 15.5906939506531 t9500-gitweb-standalone-no-errors.sh\n 15.4882569313049 t6030-bisect-porcelain.sh\n 14.487174987793 t7610-mergetool.sh\n 13.8276169300079 t3425-rebase-topology-merges.sh\n 12.7450480461121 t3426-rebase-submodule.sh\n 12.4915001392365 t3415-rebase-autosquash.sh\n 11.8122401237488 t5572-pull-submodule.sh\n"},{"id":"304458","messageId":"alpine.DEB.2.20.1610201154070.3264@virtualbox","threadId":"44329","inReplyTo":"xmqqbmygmehv.fsf@gitster.mtv.corp.google.com","subject":"Re: Drastic jump in the time required for the test suite","fromName":"Johannes Schindelin","fromEmail":"johannes.schindelin@gmx.de","sentAt":"2016-10-20T10:17:33Z","receivedAt":"2016-10-20T10:17:51Z","isPatch":false,"sender":{"key":"johannes.schindelin@gmx.de","avatar":"https://avatars.githubusercontent.com/u/127790?v=4"},"body":"Hi Junio,\n\nOn Wed, 19 Oct 2016, Junio C Hamano wrote:\n\n> Johannes Schindelin writes:\n> \n> > What I can also say for certain is that the version from yesterday (commit\n> > 4ef44ce) was the first one in a week that built successfully and hence\n> > reached the test phase, and it was the first version of `pu` ever to time\n> > out after running for 3h.\n> \n> I am sympathetic, but I'd be lying if I said I can feel your pain.\n\nObviously.\n\n> Admittedly I do not run _all_ the tests (I certainly know that I\n> exclude the ones behind EXPENSIVE prerequisite), but after every\n> rebuilding of 'jch' and 'pu', I run the testsuite (and also rebuild\n> docs) before pushing them out, and \"make test && make doc && make\n> install install-doc\" run sequentially for the four integration\n> branches finishes within 15 minutes, even when I run them after\n> \"make clean\".\n\nYou have the luxury of a system that runs shell scripts fast.\n\nOr maybe I should put it differently: you set up the test suite in such a\nway that it runs fast on your system, exploiting the fact that shell\nscripts run fast there.\n\nIf you want to know just how harmful this reliance on shell scripting is\nto our goal of keeping Git portable: already moving from Linux to MacOSX\ncosts you roughly 3x as long to run the build & test (~12mins vs ~36mins\nfor GCC, according to https://travis-ci.org/git/git/builds/159125647).\n\nAgain, I have to repeat myself: this is not good.\n\n> Perhaps the recent change to run the tests in parallel from slower\n> to faster under prove may be helping my case.\n\nNo, you misunderstand. The tests are *already* run in parallel. And\nrunning them from slower to faster would only make a difference if the\nlast tests were not requiring roughly the same time to run.\n\nAlso, I cannot use prove(1) because it proved to be unreliable in my setup\n(it does hang from time to time, for no good reason whatsoever, which\nwould only make my situation worse, of course).\n\n> > Maybe we should start optimizing the tests...\n> \n> Yup, two things that come to mind are to identify long ones and see\n> if each of them can be split into two halves that can be run in\n> parallel, and to go through the tests with fine toothed comb and\n> remove the ones that test exactly the same thing as another test.\n> The latter would be very time consuming, though.\n\nAgain, you misunderstand.\n\nThe problem is not whether or not to run the tests in parallel.\n\nThe problem is that our tests take an insanely long time to run. That is a\nbig problem, it is no good, tests are only useful if they are cheap enough\nto run all the time.\n\nSo the only thing that would really count as an improvement would be to\nchange the test suite in such a manner that it relies more on helpers in\nt/helper/ and less on heavy-duty shell scripting.\n\nOf course, if you continue to resist (because the problem is obviously not\naffecting you personally, so why would you care), I won't even try to find\nthe time to start on that project.\n\nCiao,\nDscho\n\nP.S.: After increasing the time-out to 240 minutes, the test suite still\ntimes out. I investigated a little bit and it appears that\nt6030-bisect-porcelain.sh now hangs in the `git bisect next` call of its\n\"2 - bisect starts with only one bad\" test case. This is specific to\nWindows, I cannot reproduce that problem on Linux, and I will keep you\nposted on my progress.\n"},{"id":"304459","messageId":"alpine.DEB.2.20.1610201218060.3264@virtualbox","threadId":"44329","inReplyTo":"20161019205638.m3ytxozzmeh47ml2@sigill.intra.peff.net","subject":"Re: Drastic jump in the time required for the test suite","fromName":"Johannes Schindelin","fromEmail":"johannes.schindelin@gmx.de","sentAt":"2016-10-20T10:50:32Z","receivedAt":"2016-10-20T10:51:00Z","isPatch":false,"sender":{"key":"johannes.schindelin@gmx.de","avatar":"https://avatars.githubusercontent.com/u/127790?v=4"},"body":"Hi peff,\n\nOn Wed, 19 Oct 2016, Jeff King wrote:\n\n> On Wed, Oct 19, 2016 at 10:32:12AM -0700, Junio C Hamano wrote:\n> \n> > > Maybe we should start optimizing the tests...\n> > \n> > Yup, two things that come to mind are to identify long ones and see if\n> > each of them can be split into two halves that can be run in parallel,\n> > and to go through the tests with fine toothed comb and remove the ones\n> > that test exactly the same thing as another test. The latter would be\n> > very time consuming, though.\n> \n> FWIW, I have made attempts at \"split long ones into two\" before, and\n> didn't come up with much. There _are_ some tests that are much longer\n> than others[1], but they are not longer than the whole suite takes to\n> run. So running in slow-to-fast order means they start first, are run in\n> parallel with the other tests, and the CPUs stay relatively full through\n> the whole run.\n\nThat reflects my findings, too. I want to add that I found preciously\nlittle difference between running slow-to-fast and running in numeric\norder, so I gave up on optimizing on that front.\n\n> 43.216765165329 t3404-rebase-interactive.sh\n> 30.6568658351898 t3421-rebase-topology-linear.sh\n> 27.92564702034 t9001-send-email.sh\n> 15.5906939506531 t9500-gitweb-standalone-no-errors.sh\n> 15.4882569313049 t6030-bisect-porcelain.sh\n> 14.487174987793 t7610-mergetool.sh\n> 13.8276169300079 t3425-rebase-topology-merges.sh\n> 12.7450480461121 t3426-rebase-submodule.sh\n> 12.4915001392365 t3415-rebase-autosquash.sh\n> 11.8122401237488 t5572-pull-submodule.sh\n\nThat looks very similar to what I found: t3404 on top, followed by t3421.\n\nFurther, I found that the Subversion tests (which run at the end) are so\nclose in their running time that running the tests in parallel with -j5\ndoes not result in any noticeable improvement when reordered.\n\nI guess I will have to bite into the sour apple and try to profile, say,\nt3404 somehow, including all the shell scripting stuff, to identify where\nexactly all that time is lost. My guess is that it boils down to\ngazillions of calls to programs like expr.exe or merely subshells.\n\nCiao,\nDscho\n"},{"id":"304460","messageId":"CACsJy8ALRjnvgM6sW5ioFHtquSR6zgQHkQ6-LUnKFnqXV9eDCQ@mail.gmail.com","threadId":"44329","inReplyTo":"alpine.DEB.2.20.1610191049040.3847@virtualbox","subject":"Re: Drastic jump in the time required for the test suite","fromName":"Duy Nguyen","fromEmail":"pclouds@gmail.com","sentAt":"2016-10-20T11:02:43Z","receivedAt":"2016-10-20T11:03:29Z","isPatch":false,"sender":{"key":"pclouds@gmail.com","avatar":"https://avatars.githubusercontent.com/u/720?v=4"},"body":"On Wed, Oct 19, 2016 at 4:18 PM, Johannes Schindelin\n wrote:\n> Hi Junio,\n>\n> I know you are a fan of testing things thoroughly in the test suite, but I\n> have to say that it is getting out of hand, in particular due to our\n> over-use of shell script idioms (which really only run fast on Linux, not\n> a good idea for a portable software).\n>\n> My builds of `pu` now time out, after running for 3h straight in the VM\n> dedicated to perform the daily routine of building and testing the git.git\n> branches in Git for Windows' SDK. For comparison, `next` passes build &\n> tests in 2.6h. That is quite the jump.\n\nI'm just curious, will running git.exe from WSL [1] help speed things\nup a bit (or, hopefully, a lot)? I'm assuming that shell's speed in\nWSL is quite fast.\n\nI'm pretty sure the test suite would need some adaptation, but if the\nspeedup is significant, maybe it's worth spending time on.\n\n[1] https://news.ycombinator.com/item?id=12748395\n-- \nDuy\n"},{"id":"304461","messageId":"20161020113903.tx6aqkhc2g25ba3p@sigill.intra.peff.net","threadId":"44329","inReplyTo":"alpine.DEB.2.20.1610201218060.3264@virtualbox","subject":"Re: Drastic jump in the time required for the test suite","fromName":"Jeff King","fromEmail":"peff@peff.net","sentAt":"2016-10-20T11:39:03Z","receivedAt":"2016-10-20T11:39:17Z","isPatch":false,"sender":{"key":"peff@peff.net","avatar":"https://avatars.githubusercontent.com/u/45925?v=4"},"body":"On Thu, Oct 20, 2016 at 12:50:32PM +0200, Johannes Schindelin wrote:\n\n> That reflects my findings, too. I want to add that I found preciously\n> little difference between running slow-to-fast and running in numeric\n> order, so I gave up on optimizing on that front.\n\nInteresting. It makes a 10-15% difference here.\n\nI also point \"--root\" at a ram disk. The tests are very I/O heavy and\nsometimes fsync; even on a system with an SSD, this saves another ~10%.\n\nI know that's small potatoes compared to the Windows vs Linux times, but\nit might be worth exploring.\n\n> Further, I found that the Subversion tests (which run at the end) are so\n> close in their running time that running the tests in parallel with -j5\n> does not result in any noticeable improvement when reordered.\n\nI normally don't run the Subversion tests at all. Installing cvs, cvsps,\nsubversion, and libsvn-perl nearly doubles the runtime of the test suite\nfor me (I imagine adding p4 to the mix would bump it further). While\nit's certainly possible to break them with a change in core git, it\ndoesn't seem like a good tradeoff if I'm not touching them often.\n\nAs the GfW maintainer, you probably should be running them, at least\nbefore a release. But cutting them might be a good way to speed up your\nday-to-day runs.\n\nI also use -j16 on a quad-core (+hyperthreads) machine, which I arrived\nat experimentally. At least on Linux, it's definitely worth having more\nthreads than processors, to keep the processors busy.\n\n> I guess I will have to bite into the sour apple and try to profile, say,\n> t3404 somehow, including all the shell scripting stuff, to identify where\n> exactly all that time is lost. My guess is that it boils down to\n> gazillions of calls to programs like expr.exe or merely subshells.\n\nI'm not so sure it isn't gazillions of calls to git. It is testing\nrebase, after all, which is itself a shell script. GIT_TRACE_PERFORMANCE\ngives sort of a crude measure; it reports only builtins (so it will\nunderestimate the total time spent in git), but it also doesn't make\nclear which programs call which, so some times are double-counted (if a\nbuiltin shells out to another builtin). But:\n\n $ export GIT_TRACE_PERFORMANCE=/tmp/foo.out\n $ rm /tmp/foo.out\n $ time ./t3404-rebase-interactive.sh\n real 0m29.755s\n user 0m1.444s\n sys 0m2.268s\n\n $ perl -lne '\n /performance: ([0-9.]+)/ and $total += $1;\n END { print $total }\n ' /tmp/foo.out\n 32.851352624\n\nClearly that's not 100% accurate, as it claims we spent longer in git\nthan the script actually took to run. Given the caveats above, I'm not\neven sure if it is in the right ballpark. But there are 11,000 git\nbuiltins run as part of that script. Even at 2ms each, that's still most\nof the time going to git.\n\nAnd obviously the fix involves converting git-rebase, which you're\nalready working on. But it's not clear to me that the test\ninfrastructure or shell scripts are the primary cause of the slowness in\nthis particular case.\n\n-Peff\n"},{"id":"304465","messageId":"20161020123111.qnbsainul2g54z4z@sigill.intra.peff.net","threadId":"44329","inReplyTo":"alpine.DEB.2.20.1610201154070.3264@virtualbox","subject":"Re: Drastic jump in the time required for the test suite","fromName":"Jeff King","fromEmail":"peff@peff.net","sentAt":"2016-10-20T12:31:11Z","receivedAt":"2016-10-20T12:31:20Z","isPatch":false,"sender":{"key":"peff@peff.net","avatar":"https://avatars.githubusercontent.com/u/45925?v=4"},"body":"On Thu, Oct 20, 2016 at 12:17:33PM +0200, Johannes Schindelin wrote:\n\n> If you want to know just how harmful this reliance on shell scripting is\n> to our goal of keeping Git portable: already moving from Linux to MacOSX\n> costs you roughly 3x as long to run the build & test (~12mins vs ~36mins\n> for GCC, according to https://travis-ci.org/git/git/builds/159125647).\n\nWait, shell scripts are slow on MacOS now?\n\nPerhaps, but it seems more likely that one or more of the following is\ntrue:\n\n - setup of the OS X VM takes longer (it does; if you click-through to\n the test results, you'll see that the \"make test\" step goes from\n 647s on Linux to 1108s on MacOS. That's much worse, but not even\n twice as slow, let alone 3x).\n\n - Travis Linux and OSX VMs do not have identical hardware. Looking at\n https://docs.travis-ci.com/user/ci-environment/, it appears that\n Linux containers get twice as many cores.\n\n - Git performance on Linux may be better than MacOS. The test suite is\n very filesystem-heavy because it creates and destroys a lot of files\n and repositories. If the kernel vfs performance is worse, it's\n likely to show up in the test suite (especially if the issue is\n latency and you aren't doing it massively in parallel).\n\n I don't have a real way to measure that, but it seems like a\n plausible factor.\n\nSo that sucks that the MacOS Travis build takes a half hour to run. But\nI don't think that shell scripting is the culprit.\n\n> So the only thing that would really count as an improvement would be to\n> change the test suite in such a manner that it relies more on helpers in\n> t/helper/ and less on heavy-duty shell scripting.\n> \n> Of course, if you continue to resist (because the problem is obviously not\n> affecting you personally, so why would you care), I won't even try to find\n> the time to start on that project.\n\nI'm not sure what you mean by \"resist\". The tests suite has been a set\nof shell scripts for over a decade. As far as I know there is not\ncurrently a viable alternative. If you have patches that make it faster\nwithout negatively impact the ease of writing tests, I'd be happy to see\nthem. If you have more t/helper programs that can eliminate expensive\nbits of the shell scripts and speed up the test run, great. If you have\nsome other proposal entirely, I'd love to hear it. But I do not see\nthat there is any proposal to \"resist\" at this point.\n\nI'm also not entirely convinced that the test suite being a shell script\nis the main culprit for its slowness. We run git a lot of times, and\nthat's inherent in testing it. I ran the whole test suite under\n\"strace -f -e execve\". There are ~335K execs. Here's the breakdown of\nthe top ones:\n\n$ perl -lne '/execve\\(\"(.*?)\"/ and print $1' /tmp/foo.out | sort | uniq -c | sort -rn | head\n 152271 /home/peff/compile/git/git\n 57340 /home/peff/compile/git/t/../bin-wrappers/git\n 16865 /bin/sed\n 12650 /bin/rm\n 11257 /bin/cat\n 9326 /home/peff/compile/git/git-sh-i18n--envsubst\n 9079 /usr/bin/diff\n 8013 /usr/bin/wc\n 5924 /bin/mv\n 4566 /bin/grep\n\nAlmost half are running git itself. Let's assume that can't be changed.\nThat leaves ~180K of shell-related overhead (versus the optimal case,\nthat the entire test suite becomes one monolithic program ;) ).\n\nClose to 1/3 of those processes are just invoking the bin-wrapper\nscript to set up the EXEC_PATH, etc. I imagine it would not be too hard\nto just do that in the test script. In fact, it looks like:\n\n make prefix=/wherever install\n GIT_TEST_INSTALLED=/wherever/bin make test\n\nmight give you an immediate speedup by skipping bin-wrappers entirely.\n\nThe rest of it is harder. I think you'd have to move the test suite to a\nlanguage like perl that can do more of that as builtins (I'm sure you'd\nenjoy the portability implications of _that_). It would almost be\neasier to build a variant of the shell that has sed, rm, cat, and a few\nothers compiled in.\n\n-Peff\n\nPS I haven't kept up with all of this POSIX-layer stuff that's been\n announced in Windows the past few months. Is it a viable path forward\n that would have better performance (obviously not in the short term,\n but where we may arrive in a few years)?\n"},{"id":"304471","messageId":"xmqqmvhzhu6f.fsf@gitster.mtv.corp.google.com","threadId":"44329","inReplyTo":"alpine.DEB.2.20.1610201154070.3264@virtualbox","subject":"Re: Drastic jump in the time required for the test suite","fromName":"Junio C Hamano","fromEmail":"gitster@pobox.com","sentAt":"2016-10-20T16:16:56Z","receivedAt":"2016-10-20T16:17:04Z","isPatch":false,"sender":{"key":"gitster@pobox.com","avatar":"https://avatars.githubusercontent.com/u/54884?v=4"},"body":"Johannes Schindelin writes:\n\n> Of course, if you continue to resist (because the problem is obviously not\n> affecting you personally, so why would you care), I won't even try to find\n> the time to start on that project.\n\nSorry, but I did not know I was resisting, as I didn't see any\nproposal to resist against in the first place. I was trying to help\nby mentioning two tricks that may be helping my test runtime that\nmay help you as well.\n\nAre you proposing to replace the tests written as shell scripts with\nscripts in another language or framework that run equivalent\nsequences of git commands that is as portable as, if not more,\nBourne shell? If that is what you are proposing, well, I won't stop\nyou and I may even help you in there, but I fail to guess what\nalternative you have in mind. I certainly do not have a suggestion\nmyself and I won't suggest migrate to tclsh or perl for that matter.\n\nIf that is not what you are trying to propose, and if parallelism\nhas already been employed, then there may or may not be other tricks\nyou are not yet using that helps to speed up your shell execution\nthat others are using---being confrontational is not an effective\nway to ask others about them.\n"},{"id":"304477","messageId":"CAGZ79ka_McRkOyKH3diCXJSdCm+4pNZfqAqJW_tQLFdhb26tRQ@mail.gmail.com","threadId":"44329","inReplyTo":"20161020123111.qnbsainul2g54z4z@sigill.intra.peff.net","subject":"Re: Drastic jump in the time required for the test suite","fromName":"Stefan Beller","fromEmail":"sbeller@google.com","sentAt":"2016-10-20T16:30:27Z","receivedAt":"2016-10-20T16:30:35Z","isPatch":false,"sender":{"key":"stefanbeller@gmail.com","avatar":"https://avatars.githubusercontent.com/u/455868?v=4"},"body":"On Thu, Oct 20, 2016 at 5:31 AM, Jeff King wrote:\n\n>\n> $ perl -lne '/execve\\(\"(.*?)\"/ and print $1' /tmp/foo.out | sort | uniq -c | sort -rn | head\n> 152271 /home/peff/compile/git/git\n> 57340 /home/peff/compile/git/t/../bin-wrappers/git\n> 16865 /bin/sed\n> 12650 /bin/rm\n> 11257 /bin/cat\n> 9326 /home/peff/compile/git/git-sh-i18n--envsubst\n> 9079 /usr/bin/diff\n> 8013 /usr/bin/wc\n> 5924 /bin/mv\n> 4566 /bin/grep\n>\n\nI am not an expert on perl nor tracing, but is it feasible to find out\nhow many internal calls there are? i.e. either some shell script (rebase,\nsubmodule) calling git itself a couple of times or even from compile/git/git\nitself, e.g. some submodule operations use forking in there.\n"},{"id":"304479","messageId":"e0e320ce-14a1-b4a8-aa07-6bc4f3c4a424@web.de","threadId":"44329","inReplyTo":"CACsJy8ALRjnvgM6sW5ioFHtquSR6zgQHkQ6-LUnKFnqXV9eDCQ@mail.gmail.com","subject":"Re: Drastic jump in the time required for the test suite","fromName":"René Scharfe","fromEmail":"l.s.r@web.de","sentAt":"2016-10-20T16:40:18Z","receivedAt":"2016-10-20T16:40:32Z","isPatch":false,"sender":{"key":"l.s.r@web.de","avatar":"https://avatars.githubusercontent.com/u/26122331?v=4"},"body":"Am 20.10.2016 um 13:02 schrieb Duy Nguyen:\n> On Wed, Oct 19, 2016 at 4:18 PM, Johannes Schindelin\n> wrote:\n>> Hi Junio,\n>>\n>> I know you are a fan of testing things thoroughly in the test suite, but I\n>> have to say that it is getting out of hand, in particular due to our\n>> over-use of shell script idioms (which really only run fast on Linux, not\n>> a good idea for a portable software).\n>>\n>> My builds of `pu` now time out, after running for 3h straight in the VM\n>> dedicated to perform the daily routine of building and testing the git.git\n>> branches in Git for Windows' SDK. For comparison, `next` passes build &\n>> tests in 2.6h. That is quite the jump.\n> \n> I'm just curious, will running git.exe from WSL [1] help speed things\n> up a bit (or, hopefully, a lot)? I'm assuming that shell's speed in\n> WSL is quite fast.\n> \n> I'm pretty sure the test suite would need some adaptation, but if the\n> speedup is significant, maybe it's worth spending time on.\n> \n> [1] https://news.ycombinator.com/item?id=12748395\n\nI get this on WSL with prove -j8:\n\nFiles=750, Tests=13657, 906 wallclock secs ( 8.51 usr 17.17 sys + 282.62 cusr 3731.85 csys = 4040.15 CPU)\n\nAnd this for a run on Debian inside a Hyper-V VM on the same system:\n\nFiles=759, Tests=13895, 99 wallclock secs ( 4.81 usr 1.06 sys + 39.70 cusr 25.82 csys = 71.39 CPU)\n\nAll tests pass on master.\n\nRené\n\n"},{"id":"304483","messageId":"vpqinsnndtg.fsf@anie.imag.fr","threadId":"44329","inReplyTo":"xmqqmvhzhu6f.fsf@gitster.mtv.corp.google.com","subject":"Re: Drastic jump in the time required for the test suite","fromName":"Matthieu Moy","fromEmail":"matthieu.moy@grenoble-inp.fr","sentAt":"2016-10-20T17:13:47Z","receivedAt":"2016-10-20T17:14:13Z","isPatch":false,"sender":{"key":"matthieu.moy@grenoble-inp.fr","avatar":"https://gravatar.com/avatar/72c8a2705971a25dfaff23cece15130d405685845d911aedd5667ace277f3fc5?d=mp&s=160"},"body":"Junio C Hamano writes:\n\n> Are you proposing to replace the tests written as shell scripts with\n> scripts in another language or framework that run equivalent\n> sequences of git commands that is as portable as, if not more,\n> Bourne shell?\n\nThe language (/bin/sh) is probably not the biggest issue. The way we use\nit may be.\n\nI don't have benchmark to tell what slows down the testsuite, but for\nexample we often write\n\n\tcat >expected <actual &&\n\ttest_cmp expected actual\n\nWe create 2 files, fork one 'cat' and one 'diff'. Now, suppose we can\nwrite instead\n\n\ttest_check_output git foo < wrote:\n> Hi peff,\n>\n> On Wed, 19 Oct 2016, Jeff King wrote:\n>\n>> On Wed, Oct 19, 2016 at 10:32:12AM -0700, Junio C Hamano wrote:\n>>\n>> > > Maybe we should start optimizing the tests...\n>> >\n\nMaybe we should stop introducing un-optimized tests.\nFor other reasons I just stumbled upon t7064\n(porcelain V2 output for git status)\n\n\nThis is how an arbitrary test looks like:\n\ntest_expect_success 'staged changes in added submodule (AM S.M.)' '\n ( cd super_repo &&\n ## stage the changes in the submodule.\n ( cd sub1 &&\n git add file_in_sub\n ) &&\n\n HMOD=$(git hash-object -t blob -- .gitmodules) &&\n HSUP=$(git rev-parse HEAD) &&\n HSUB=$HSUP &&\n\n cat >expect <<-EOF &&\n # branch.oid $HSUP\n # branch.head master\n # branch.upstream origin/master\n # branch.ab +0 -0\n 1 A. N... 000000 100644 100644 $_z40 $HMOD .gitmodules\n 1 AM S.M. 000000 160000 160000 $_z40 $HSUB sub1\n EOF\n\n git status --porcelain=v2 --branch --untracked-files=all >actual &&\n test_cmp expect actual\n )\n'\n\nFollowing \"modern\" Git tests I would have expected:\n\n* heavy use of the \"git -C \" pattern. When applying that\n thouroughly we'd save spanning the subshells.\n* no `cd` on the same line as the opening paren.\n (This is style and would derail the performance discussion)\n\ntest_expect_success 'staged changes in added submodule (AM S.M.)' '\n git -C super_repo/sub1 add file_in_sub &&\n HMOD=$(git -C super_repo hash-object -t blob -- .gitmodules) &&\n HSUP=$(git -C super_repo rev-parse HEAD) &&\n # as a comment: HSUB is equal to HSUP, because ...\n\n cat >expect <<-EOF &&\n # branch.oid $HSUP\n # branch.head master\n # branch.upstream origin/master\n # branch.ab +0 -0\n 1 A. N... 000000 100644 100644 $_z40 $HMOD .gitmodules\n 1 AM S.M. 000000 160000 160000 $_z40 $HSUP sub1\n EOF\n\n git -C super_repo status --porcelain=v2 --branch\n--untracked-files=all >../actual &&\n test_cmp expect actual\n'\n\nThat said I really like the idea of having a helper that would eliminate the cat\nfor you, e.g. :\n\ngit_test_helper_equal_stdin_or_diff_and_die -C super_repo status\n--porcelain=v2 --branch --untracked-files=all <<-EOF\n1 A. N... 000000 100644 100644 $_z40 $HMOD .gitmodules\n1 AM S.M. 000000 160000 160000 $_z40 $HSUP sub1\nEOF\n\nThanks,\nStefan\n"},{"id":"304513","messageId":"530a3bca-e251-cb43-fb6a-e99c1e64a0a7@kdbg.org","threadId":"44329","inReplyTo":"20161020123111.qnbsainul2g54z4z@sigill.intra.peff.net","subject":"Re: Drastic jump in the time required for the test suite","fromName":"Johannes Sixt","fromEmail":"j6t@kdbg.org","sentAt":"2016-10-20T20:38:23Z","receivedAt":"2016-10-20T20:38:32Z","isPatch":false,"sender":{"key":"j6t@kdbg.org","avatar":"https://avatars.githubusercontent.com/u/14810926?v=4"},"body":"Am 20.10.2016 um 14:31 schrieb Jeff King:\n> Close to 1/3 of those processes are just invoking the bin-wrapper\n> script to set up the EXEC_PATH, etc. I imagine it would not be too hard\n> to just do that in the test script. In fact, it looks like:\n>\n> make prefix=/wherever install\n> GIT_TEST_INSTALLED=/wherever/bin make test\n>\n> might give you an immediate speedup by skipping bin-wrappers entirely.\n\nRunning the tests with --with-dashes should give you the same effect, no?\n\n-- Hannes\n\n"},{"id":"304515","messageId":"1476996017.28685.10.camel@kaarsemaker.net","threadId":"44329","inReplyTo":"20161020123111.qnbsainul2g54z4z@sigill.intra.peff.net","subject":"Re: Drastic jump in the time required for the test suite","fromName":"Dennis Kaarsemaker","fromEmail":"dennis@kaarsemaker.net","sentAt":"2016-10-20T20:40:17Z","receivedAt":"2016-10-20T20:40:24Z","isPatch":false,"sender":{"key":"dennis@kaarsemaker.net","avatar":"https://avatars.githubusercontent.com/u/200649?v=4"},"body":"On Thu, 2016-10-20 at 08:31 -0400, Jeff King wrote:\n\n> I'm also not entirely convinced that the test suite being a shell script\n> is the main culprit for its slowness. We run git a lot of times, and\n> that's inherent in testing it. I ran the whole test suite under\n> \"strace -f -e execve\". There are ~335K execs. Here's the breakdown of\n> the top ones:\n\nYou're measuring execve's, but fork (well, fork emulation. There's no\nactual fork) is also expensive on windows iirc, so subshells add a lot\nto this cost. That said, strace -eclone says that a 'make test' forks\n~408k times, and while this is significantly more than the amount of\nexecs in your example, this does include cvs and svn tests and it's\nstill in the same ballpark.\n\nD.\n"},{"id":"304517","messageId":"20161020210013.57wkyhmf2ism6vt2@sigill.intra.peff.net","threadId":"44329","inReplyTo":"CAGZ79ka_McRkOyKH3diCXJSdCm+4pNZfqAqJW_tQLFdhb26tRQ@mail.gmail.com","subject":"Re: Drastic jump in the time required for the test suite","fromName":"Jeff King","fromEmail":"peff@peff.net","sentAt":"2016-10-20T21:00:13Z","receivedAt":"2016-10-20T21:00:21Z","isPatch":false,"sender":{"key":"peff@peff.net","avatar":"https://avatars.githubusercontent.com/u/45925?v=4"},"body":"On Thu, Oct 20, 2016 at 09:30:27AM -0700, Stefan Beller wrote:\n\n> On Thu, Oct 20, 2016 at 5:31 AM, Jeff King wrote:\n> \n> >\n> > $ perl -lne '/execve\\(\"(.*?)\"/ and print $1' /tmp/foo.out | sort | uniq -c | sort -rn | head\n> > 152271 /home/peff/compile/git/git\n> > 57340 /home/peff/compile/git/t/../bin-wrappers/git\n> > 16865 /bin/sed\n> > 12650 /bin/rm\n> > 11257 /bin/cat\n> > 9326 /home/peff/compile/git/git-sh-i18n--envsubst\n> > 9079 /usr/bin/diff\n> > 8013 /usr/bin/wc\n> > 5924 /bin/mv\n> > 4566 /bin/grep\n> >\n> \n> I am not an expert on perl nor tracing, but is it feasible to find out\n> how many internal calls there are? i.e. either some shell script (rebase,\n> submodule) calling git itself a couple of times or even from compile/git/git\n> itself, e.g. some submodule operations use forking in there.\n\nThe script below is my attempt, though I think it is not quite right, as\n\"make\" should be the single apex of the graph. You can run it like:\n\n strace -f -o /tmp/foo.out -e clone,execve make test\n perl graph.pl /tmp/foo.out | less -S\n\nOne thing that it counts (that was not counted above) is the number of\nforks for subshells, which is considerable. I don't know how expensive\nthat is versus, say, running \"cat\" (if your fork() doesn't\ncopy-on-write, and you implement sub-programs via an efficient spawn()\ncall, it's possible that the subshells are significantly more\nexpensive).\n\n-Peff\n\n-- >8 --\n#!/usr/bin/perl\n\nmy %clone;\nmy %exec;\nmy %is_child;\nmy %counter;\nwhile (<>) {\n\t# execve(\"some-prog\", ...\n\tif (/^(\\d+)\\s+execve\\(\"(.*?)\"/) {\n\t\tpush @{$exec{node($1)}}, $2;\n\t}\n\t# clone(...) = \n\t# or\n\t# <... clone resumed> ...) = \n\telsif (/^(\\d+)\\s+.*clone.*\\) = (\\d+)$/) {\n\t\tpush @{$clone{node($1)}}, node($2);\n\t\t$is_child{node($2)} = 1;\n\t}\n\t# +++ exited with +++\n\t# We have to keep track of this because pids get recycled,\n\t# and so are not unique node names in our graph.\n\telsif (/^(\\d+)\\s+.*exited with/) {\n\t\t$counter{$1}++;\n\t}\n}\n\nshow($_, 0) for grep { !$is_child{$_} } keys(%clone);\n\nsub show {\n\tmy ($pid, $indent) = @_;\n\n\tmy @progs = @{$exec{$pid}};\n\tif (!@progs) {\n\t\t@progs = (\"(fork)\");\n\t}\n\n\tprint ' ' x $indent;\n\tprint \"$pid: \", shift @progs;\n\tprint \" => $_\" for @progs;\n\tprint \"\\n\";\n\n\tshow($_, $indent + 2) for @{$clone{$pid}};\n}\n\nsub node {\n\tmy $pid = shift;\n\tmy $c = $counter{$pid} || \"0\";\n\treturn \"$pid-$c\";\n}\n"},{"id":"304518","messageId":"20161020210301.fwuskzylrj6u23ja@sigill.intra.peff.net","threadId":"44329","inReplyTo":"530a3bca-e251-cb43-fb6a-e99c1e64a0a7@kdbg.org","subject":"Re: Drastic jump in the time required for the test suite","fromName":"Jeff King","fromEmail":"peff@peff.net","sentAt":"2016-10-20T21:03:01Z","receivedAt":"2016-10-20T21:03:08Z","isPatch":false,"sender":{"key":"peff@peff.net","avatar":"https://avatars.githubusercontent.com/u/45925?v=4"},"body":"On Thu, Oct 20, 2016 at 10:38:23PM +0200, Johannes Sixt wrote:\n\n> Am 20.10.2016 um 14:31 schrieb Jeff King:\n> > Close to 1/3 of those processes are just invoking the bin-wrapper\n> > script to set up the EXEC_PATH, etc. I imagine it would not be too hard\n> > to just do that in the test script. In fact, it looks like:\n> > \n> > make prefix=/wherever install\n> > GIT_TEST_INSTALLED=/wherever/bin make test\n> > \n> > might give you an immediate speedup by skipping bin-wrappers entirely.\n> \n> Running the tests with --with-dashes should give you the same effect, no?\n\nYeah, looks like it. it still uses bin-wrappers for t/helper, but that\nshould be a minority of calls.\n\nWhich I think explains why I saw some test failures with the\nGIT_TEST_INSTALLED above. It does not know about t/helper, but relies on\nthose programs being present in $GIT_BUILD_DIR. So I suspect it has been\ntotally broken since e6e7530d10 (test helpers: move test-* to t/helper/\nsubdirectory, 2016-04-13).\n\n-Peff\n"},{"id":"304520","messageId":"20161020213803.7d7bymby7pouzij3@sigill.intra.peff.net","threadId":"44329","inReplyTo":"CAGZ79kZpj5xXHmnA+JfLKdGmgzp7Mut1OsKMOeowpw8m1+aKGA@mail.gmail.com","subject":"Re: Drastic jump in the time required for the test suite","fromName":"Jeff King","fromEmail":"peff@peff.net","sentAt":"2016-10-20T21:38:03Z","receivedAt":"2016-10-20T21:38:10Z","isPatch":false,"sender":{"key":"peff@peff.net","avatar":"https://avatars.githubusercontent.com/u/45925?v=4"},"body":"On Thu, Oct 20, 2016 at 12:54:32PM -0700, Stefan Beller wrote:\n\n> Maybe we should stop introducing un-optimized tests.\n> [...]\n> * heavy use of the \"git -C \" pattern. When applying that\n> thouroughly we'd save spanning the subshells.\n\nYeah, I imagine with some style changes we could drop quite a few\nsubshells. The problem is that the conversion work is manual and\ntedious. I'd look first for spots where we can eliminate thousands of\ncalls with a single change.\n\n> That said I really like the idea of having a helper that would eliminate the cat\n> for you, e.g. :\n> \n> git_test_helper_equal_stdin_or_diff_and_die -C super_repo status\n> --porcelain=v2 --branch --untracked-files=all <<-EOF\n> 1 A. N... 000000 100644 100644 $_z40 $HMOD .gitmodules\n> 1 AM S.M. 000000 160000 160000 $_z40 $HSUP sub1\n> EOF\n\nI think that helper still ends up using \"cat\" and \"diff\" under the hood,\nunless you write those bits in pure shell. But at that point, I suspect\nwe could \"cat\" and \"test_cmp\" in pure shell, something like:\n\n\tcat () {\n\t\t# optimize common here-doc usage\n\t\tif test $# -eq 0\n\t\tthen\n\t\t\twhile read -r line\n\t\t\tdo\n\t\t\t\tprintf '%s' \"$line\"\n\t\t\tdone\n\t\tfi\n\t\tcommand cat \"$@\"\n\t}\n\n\ttest_cmp () {\n\t\t# optimize for common \"they are the same\" case\n\t\t# without any subshells or subprograms\n\t\twhile true; do\n\t\t\tif ! read -r line1 <&3\n\t\t\tthen\n\t\t\t\tif ! read -r line2 <&4\n\t\t\t\t\t# EOF on both; good\n\t\t\t\t\treturn 0\n\t\t\t\telse\n\t\t\t\t\t# EOF only on file1; fail\n\t\t\t\t\tbreak\n\t\t\t\tfi\n\t\t\tfi\n\t\t\tif ! read -r line2 <&4\n\t\t\tthen\n\t\t\t\t# EOF only on file2; fail\n\t\t\t\tbreak\n\t\t\tfi\n\t\t\ttest \"$line1\" = \"$line2\" || break\n\t\tdone 3<\"$1\" 4<\"$2\"\n\n\t\t# if we get here, the optimized version found some\n\t\t# difference. We can just \"return 1\", but let's run\n\t\t# the real $GIT_TEST_CMP to provide pretty output.\n\t\t# This should generally only happen on test failures,\n\t\t# so performance isn't a big deal.\n\t\t\"$GIT_TEST_CMP\" \"$@\"\n\t}\n\nThose are both completely untested. But maybe they are worth playing\naround with for somebody on Windows to see if they make a dent in the\ntest runtime.\n\n-Peff\n"},{"id":"304533","messageId":"CAGZ79kZkSwbiYD=G_nSZW8_qeb2q+AOsqYipmEigTN1aNYPiEw@mail.gmail.com","threadId":"44329","inReplyTo":"20161020213803.7d7bymby7pouzij3@sigill.intra.peff.net","subject":"Re: Drastic jump in the time required for the test suite","fromName":"Stefan Beller","fromEmail":"sbeller@google.com","sentAt":"2016-10-20T21:53:36Z","receivedAt":"2016-10-20T21:53:43Z","isPatch":false,"sender":{"key":"stefanbeller@gmail.com","avatar":"https://avatars.githubusercontent.com/u/455868?v=4"},"body":"On Thu, Oct 20, 2016 at 2:38 PM, Jeff King wrote:\n> On Thu, Oct 20, 2016 at 12:54:32PM -0700, Stefan Beller wrote:\n>\n>> Maybe we should stop introducing un-optimized tests.\n>> [...]\n>> * heavy use of the \"git -C \" pattern. When applying that\n>> thouroughly we'd save spanning the subshells.\n>\n> Yeah, I imagine with some style changes we could drop quite a few\n> subshells. The problem is that the conversion work is manual and\n> tedious. I'd look first for spots where we can eliminate thousands of\n> calls with a single change.\n>\n>> That said I really like the idea of having a helper that would eliminate the cat\n>> for you, e.g. :\n>>\n>> git_test_helper_equal_stdin_or_diff_and_die -C super_repo status\n>> --porcelain=v2 --branch --untracked-files=all <<-EOF\n>> 1 A. N... 000000 100644 100644 $_z40 $HMOD .gitmodules\n>> 1 AM S.M. 000000 160000 160000 $_z40 $HSUP sub1\n>> EOF\n>\n> I think that helper still ends up using \"cat\" and \"diff\" under the hood,\n\nI assumed that helper being a C program, that only needs to fork once\nfor the actual git call and then it sits idle to compare the exact output\nfrom stdout to its stdin.\n\nIf there is a difference it will do the extra work (i.e. put stdin and stout to\na file and call diff on it)\n"},{"id":"304534","messageId":"20161020215647.5no7effvutwep2xt@sigill.intra.peff.net","threadId":"44329","inReplyTo":"20161020213803.7d7bymby7pouzij3@sigill.intra.peff.net","subject":"Re: Drastic jump in the time required for the test suite","fromName":"Jeff King","fromEmail":"peff@peff.net","sentAt":"2016-10-20T21:56:47Z","receivedAt":"2016-10-20T21:56:54Z","isPatch":false,"sender":{"key":"peff@peff.net","avatar":"https://avatars.githubusercontent.com/u/45925?v=4"},"body":"On Thu, Oct 20, 2016 at 05:38:03PM -0400, Jeff King wrote:\n\n> I think that helper still ends up using \"cat\" and \"diff\" under the hood,\n> unless you write those bits in pure shell. But at that point, I suspect\n> we could \"cat\" and \"test_cmp\" in pure shell, something like:\n> [...]\n> Those are both completely untested. But maybe they are worth playing\n> around with for somebody on Windows to see if they make a dent in the\n> test runtime.\n\nIf you tried to run them, you probably noticed that the \"untested\" was\nreally true. One of the functions was missing an \"else\", and the other\nforgot to add a \"\\n\" to its printf.\n\nThe patch below gets closer, though there are still a handful of test\nfailures. I didn't investigate deeply, but I think at least one is\nrelated to the \"read/printf\" version of cat not being binary-clean.\n\n-Peff\n\n---\ndiff --git a/t/test-lib-functions.sh b/t/test-lib-functions.sh\nindex fdaeb3a96b..de37f3d 100644\n--- a/t/test-lib-functions.sh\n+++ b/t/test-lib-functions.sh\n@@ -685,9 +685,48 @@ test_expect_code () {\n # - not all diff versions understand \"-u\"\n \n test_cmp() {\n+\t# optimize for common \"they are the same\" case\n+\t# without any subshells or subprograms\n+\twhile true; do\n+\t\tif ! read -r line1 <&3\n+\t\tthen\n+\t\t\tif ! read -r line2 <&4\n+\t\t\tthen\n+\t\t\t\t# EOF on both; good\n+\t\t\t\treturn 0\n+\t\t\telse\n+\t\t\t\t# EOF only on file1; fail\n+\t\t\t\tbreak\n+\t\t\tfi\n+\t\tfi\n+\t\tif ! read -r line2 <&4\n+\t\tthen\n+\t\t\t# EOF only on file2; fail\n+\t\t\tbreak\n+\t\tfi\n+\t\ttest \"$line1\" = \"$line2\" || break\n+\tdone 3<\"$1\" 4<\"$2\"\n+\n+\t# if we get here, the optimized version found some\n+\t# difference. We can just \"return 1\", but let's run\n+\t# the real $GIT_TEST_CMP to provide pretty output.\n+\t# This should generally only happen on test failures,\n+\t# so performance isn't a big deal.\n \t$GIT_TEST_CMP \"$@\"\n }\n \n+cat () {\n+\t# optimize common here-doc usage\n+\tif test $# -eq 0\n+\tthen\n+\t\twhile read -r line\n+\t\tdo\n+\t\t\tprintf '%s\\n' \"$line\"\n+\t\tdone\n+\tfi\n+\tcommand cat \"$@\"\n+}\n+\n # test_cmp_bin - helper to compare binary files\n \n test_cmp_bin() {\n"},{"id":"304535","messageId":"20161020215742.b5gzqvd2g6afjgmh@sigill.intra.peff.net","threadId":"44329","inReplyTo":"CAGZ79kZkSwbiYD=G_nSZW8_qeb2q+AOsqYipmEigTN1aNYPiEw@mail.gmail.com","subject":"Re: Drastic jump in the time required for the test suite","fromName":"Jeff King","fromEmail":"peff@peff.net","sentAt":"2016-10-20T21:57:42Z","receivedAt":"2016-10-20T21:57:51Z","isPatch":false,"sender":{"key":"peff@peff.net","avatar":"https://avatars.githubusercontent.com/u/45925?v=4"},"body":"On Thu, Oct 20, 2016 at 02:53:36PM -0700, Stefan Beller wrote:\n\n> >> That said I really like the idea of having a helper that would eliminate the cat\n> >> for you, e.g. :\n> >>\n> >> git_test_helper_equal_stdin_or_diff_and_die -C super_repo status\n> >> --porcelain=v2 --branch --untracked-files=all <<-EOF\n> >> 1 A. N... 000000 100644 100644 $_z40 $HMOD .gitmodules\n> >> 1 AM S.M. 000000 160000 160000 $_z40 $HSUP sub1\n> >> EOF\n> >\n> > I think that helper still ends up using \"cat\" and \"diff\" under the hood,\n> \n> I assumed that helper being a C program, that only needs to fork once\n> for the actual git call and then it sits idle to compare the exact output\n> from stdout to its stdin.\n\nAh, I see. I thought you meant a shell helper. A C helper does drop 2\nforks down to 1, but it would be nice if we could drop it to 0.\n\n-Peff\n"},{"id":"304545","messageId":"20161020232052.uggm2w7qitrj5f7g@sigill.intra.peff.net","threadId":"44329","inReplyTo":"20161020210013.57wkyhmf2ism6vt2@sigill.intra.peff.net","subject":"Re: Drastic jump in the time required for the test suite","fromName":"Jeff King","fromEmail":"peff@peff.net","sentAt":"2016-10-20T23:20:53Z","receivedAt":"2016-10-20T23:21:03Z","isPatch":false,"sender":{"key":"peff@peff.net","avatar":"https://avatars.githubusercontent.com/u/45925?v=4"},"body":"On Thu, Oct 20, 2016 at 05:00:13PM -0400, Jeff King wrote:\n\n> > I am not an expert on perl nor tracing, but is it feasible to find out\n> > how many internal calls there are? i.e. either some shell script (rebase,\n> > submodule) calling git itself a couple of times or even from compile/git/git\n> > itself, e.g. some submodule operations use forking in there.\n> \n> The script below is my attempt, though I think it is not quite right, as\n> \"make\" should be the single apex of the graph. You can run it like:\n> \n> strace -f -o /tmp/foo.out -e clone,execve make test\n> perl graph.pl /tmp/foo.out | less -S\n\nAh, I see why it is sometimes wrong. We may see parent/child\ninteractions out of order. E.g., we may see:\n\n 1. Process B execs \"git\".\n\n 2. Process B exits.\n\n 3. Process A forks pid B.\n\nbecause strace does not manage to ptrace \"A\" before \"B\" finishes\nrunning. It's hard to tell in step 3 if this is the same \"A\" we saw\nearlier. You cannot just go by PID, because the tests run enough\nprocesses that we end up reusing PIDs. My script has a hack which\nincrements a counter when processes go away, but that happens in step 2\nabove (and steps 1 and 3 think they are seeing different processes, even\nthough they are the same).\n\nI'm sure it could be cleverly hacked around, but the easiest thing is\nprobably to just make sure the tests are not run in parallel. High load\nmakes that kind of out-of-order sequence much more likely.\n\nMaking sure I run it with \"make -j1\", the script I posted earlier gives\npretty reasonable output. I won't post mine here, as it's double-digit\nmegabytes, but you should be able to recreate it yourself.\n\nOf course, the call graph by itself isn't that interesting. But you\nmight be able to do some interesting analysis, or just find spots of\ninterest to you (like git-submodule).\n\n-Peff\n"},{"id":"304557","messageId":"4d97fcc7-d15b-e7d8-c787-483c67d4a66b@kdbg.org","threadId":"44329","inReplyTo":"20161020213803.7d7bymby7pouzij3@sigill.intra.peff.net","subject":"Re: Drastic jump in the time required for the test suite","fromName":"Johannes Sixt","fromEmail":"j6t@kdbg.org","sentAt":"2016-10-21T05:27:40Z","receivedAt":"2016-10-21T05:27:48Z","isPatch":false,"sender":{"key":"j6t@kdbg.org","avatar":"https://avatars.githubusercontent.com/u/14810926?v=4"},"body":"Am 20.10.2016 um 23:38 schrieb Jeff King:\n> \ttest_cmp () {\n> \t\t# optimize for common \"they are the same\" case\n> \t\t# without any subshells or subprograms\n\nWe do this already on Windows; it's the function mingw_test_cmp in our \ntest suite:\nhttps://github.com/git/git/blob/master/t/test-lib-functions.sh#L884-L945\n\n-- Hannes\n\n"},{"id":"304561","messageId":"20161021082409.isgrvurv4ttra7ai@sigill.intra.peff.net","threadId":"44329","inReplyTo":"4d97fcc7-d15b-e7d8-c787-483c67d4a66b@kdbg.org","subject":"Re: Drastic jump in the time required for the test suite","fromName":"Jeff King","fromEmail":"peff@peff.net","sentAt":"2016-10-21T08:24:09Z","receivedAt":"2016-10-21T08:24:18Z","isPatch":false,"sender":{"key":"peff@peff.net","avatar":"https://avatars.githubusercontent.com/u/45925?v=4"},"body":"On Fri, Oct 21, 2016 at 07:27:40AM +0200, Johannes Sixt wrote:\n\n> Am 20.10.2016 um 23:38 schrieb Jeff King:\n> > \ttest_cmp () {\n> > \t\t# optimize for common \"they are the same\" case\n> > \t\t# without any subshells or subprograms\n> \n> We do this already on Windows; it's the function mingw_test_cmp in our test\n> suite:\n> https://github.com/git/git/blob/master/t/test-lib-functions.sh#L884-L945\n\nAh, thanks, I didn't even think to look for an existing solution like\nthis. Looks like it was done for LF/CRLF reasons, though, not\nperformance. I wonder if anybody has measured whether it improves things\nthere or not.\n\n-Peff\n"},{"id":"304570","messageId":"CACsJy8D-o8BeaV1jrL7ADXgVwJ=KwnBCHTCN_fuCGvS1VVpU6A@mail.gmail.com","threadId":"44329","inReplyTo":"e0e320ce-14a1-b4a8-aa07-6bc4f3c4a424@web.de","subject":"Re: Drastic jump in the time required for the test suite","fromName":"Duy Nguyen","fromEmail":"pclouds@gmail.com","sentAt":"2016-10-21T10:59:53Z","receivedAt":"2016-10-21T11:00:39Z","isPatch":false,"sender":{"key":"pclouds@gmail.com","avatar":"https://avatars.githubusercontent.com/u/720?v=4"},"body":"On Thu, Oct 20, 2016 at 11:40 PM, René Scharfe wrote:\n> Am 20.10.2016 um 13:02 schrieb Duy Nguyen:\n>> On Wed, Oct 19, 2016 at 4:18 PM, Johannes Schindelin\n>> wrote:\n>>> Hi Junio,\n>>>\n>>> I know you are a fan of testing things thoroughly in the test suite, but I\n>>> have to say that it is getting out of hand, in particular due to our\n>>> over-use of shell script idioms (which really only run fast on Linux, not\n>>> a good idea for a portable software).\n>>>\n>>> My builds of `pu` now time out, after running for 3h straight in the VM\n>>> dedicated to perform the daily routine of building and testing the git.git\n>>> branches in Git for Windows' SDK. For comparison, `next` passes build &\n>>> tests in 2.6h. That is quite the jump.\n>>\n>> I'm just curious, will running git.exe from WSL [1] help speed things\n>> up a bit (or, hopefully, a lot)? I'm assuming that shell's speed in\n>> WSL is quite fast.\n>>\n>> I'm pretty sure the test suite would need some adaptation, but if the\n>> speedup is significant, maybe it's worth spending time on.\n>>\n>> [1] https://news.ycombinator.com/item?id=12748395\n>\n> I get this on WSL with prove -j8:\n>\n> Files=750, Tests=13657, 906 wallclock secs ( 8.51 usr 17.17 sys + 282.62 cusr 3731.85 csys = 4040.15 CPU)\n>\n> And this for a run on Debian inside a Hyper-V VM on the same system:\n>\n> Files=759, Tests=13895, 99 wallclock secs ( 4.81 usr 1.06 sys + 39.70 cusr 25.82 csys = 71.39 CPU)\n>\n> All tests pass on master.\n\nThank you for doing this. 10 times slower is probably not worth\nfollowing up (though absolute numbers still look amazing, you have\nsome beefy machine there).\n-- \nDuy\n"},{"id":"304571","messageId":"CACsJy8DDO_k-gtSj-Nbc9=DvTC1FFQRmc=OtTmh-c4rc=xC_+w@mail.gmail.com","threadId":"44329","inReplyTo":"1476996017.28685.10.camel@kaarsemaker.net","subject":"Re: Drastic jump in the time required for the test suite","fromName":"Duy Nguyen","fromEmail":"pclouds@gmail.com","sentAt":"2016-10-21T11:03:32Z","receivedAt":"2016-10-21T11:04:10Z","isPatch":false,"sender":{"key":"pclouds@gmail.com","avatar":"https://avatars.githubusercontent.com/u/720?v=4"},"body":"On Fri, Oct 21, 2016 at 3:40 AM, Dennis Kaarsemaker\n wrote:\n> On Thu, 2016-10-20 at 08:31 -0400, Jeff King wrote:\n>\n>> I'm also not entirely convinced that the test suite being a shell script\n>> is the main culprit for its slowness. We run git a lot of times, and\n>> that's inherent in testing it. I ran the whole test suite under\n>> \"strace -f -e execve\". There are ~335K execs. Here's the breakdown of\n>> the top ones:\n>\n> You're measuring execve's, but fork (well, fork emulation. There's no\n> actual fork) is also expensive on windows iirc, so subshells add a lot\n> to this cost.\n\nshells fork on piping as well, and redirection and some other\nconstruct if I remember correctly (I attempted to port busybox ash to\nwindows and had to find and \"fix\" all the forks)\n\n> That said, strace -eclone says that a 'make test' forks\n> ~408k times, and while this is significantly more than the amount of\n> execs in your example, this does include cvs and svn tests and it's\n> still in the same ballpark.\n-- \nDuy\n"},{"id":"304608","messageId":"vpqd1itdf02.fsf@anie.imag.fr","threadId":"44329","inReplyTo":"e0e320ce-14a1-b4a8-aa07-6bc4f3c4a424@web.de","subject":"Re: Drastic jump in the time required for the test suite","fromName":"Matthieu Moy","fromEmail":"matthieu.moy@grenoble-inp.fr","sentAt":"2016-10-21T13:10:37Z","receivedAt":"2016-10-21T13:11:06Z","isPatch":false,"sender":{"key":"matthieu.moy@grenoble-inp.fr","avatar":"https://gravatar.com/avatar/72c8a2705971a25dfaff23cece15130d405685845d911aedd5667ace277f3fc5?d=mp&s=160"},"body":"René Scharfe writes:\n\n> I get this on WSL with prove -j8:\n>\n> Files=750, Tests=13657, 906 wallclock secs ( 8.51 usr 17.17 sys + 282.62 cusr 3731.85 csys = 4040.15 CPU)\n>\n> And this for a run on Debian inside a Hyper-V VM on the same system:\n>\n> Files=759, Tests=13895, 99 wallclock secs ( 4.81 usr 1.06 sys + 39.70 cusr 25.82 csys = 71.39 CPU)\n\nWhat about the same without WSL on windows?\n\n-- \nMatthieu Moy\nhttp://www-verimag.imag.fr/~moy/\n"},{"id":"304641","messageId":"6616be42-7c47-0b6c-28a3-e3ec70e624bf@web.de","threadId":"44329","inReplyTo":"vpqd1itdf02.fsf@anie.imag.fr","subject":"Re: Drastic jump in the time required for the test suite","fromName":"René Scharfe","fromEmail":"l.s.r@web.de","sentAt":"2016-10-21T19:57:24Z","receivedAt":"2016-10-21T19:57:41Z","isPatch":false,"sender":{"key":"l.s.r@web.de","avatar":"https://avatars.githubusercontent.com/u/26122331?v=4"},"body":"Am 21.10.2016 um 15:10 schrieb Matthieu Moy:\n> René Scharfe writes:\n> \n>> I get this on WSL with prove -j8:\n>>\n>> Files=750, Tests=13657, 906 wallclock secs ( 8.51 usr 17.17 sys + 282.62 cusr 3731.85 csys = 4040.15 CPU)\n>>\n>> And this for a run on Debian inside a Hyper-V VM on the same system:\n>>\n>> Files=759, Tests=13895, 99 wallclock secs ( 4.81 usr 1.06 sys + 39.70 cusr 25.82 csys = 71.39 CPU)\n> \n> What about the same without WSL on windows?\n\nFiles=755, Tests=14894, 1774 wallclock secs ( 9.31 usr 9.58 sys + 821.87 cusr 1961.23 csys = 2801.99 CPU)\n\nRené\n\n"},{"id":"304642","messageId":"99efe668-d459-0f8d-907c-9f212b24fa03@web.de","threadId":"44329","inReplyTo":"CACsJy8D-o8BeaV1jrL7ADXgVwJ=KwnBCHTCN_fuCGvS1VVpU6A@mail.gmail.com","subject":"Re: Drastic jump in the time required for the test suite","fromName":"René Scharfe","fromEmail":"l.s.r@web.de","sentAt":"2016-10-21T20:28:03Z","receivedAt":"2016-10-21T20:28:33Z","isPatch":false,"sender":{"key":"l.s.r@web.de","avatar":"https://avatars.githubusercontent.com/u/26122331?v=4"},"body":"Am 21.10.2016 um 12:59 schrieb Duy Nguyen:\n> On Thu, Oct 20, 2016 at 11:40 PM, René Scharfe wrote:\n>> I get this on WSL with prove -j8:\n>>\n>> Files=750, Tests=13657, 906 wallclock secs ( 8.51 usr 17.17 sys + 282.62 cusr 3731.85 csys = 4040.15 CPU)\n>>\n>> And this for a run on Debian inside a Hyper-V VM on the same system:\n>>\n>> Files=759, Tests=13895, 99 wallclock secs ( 4.81 usr 1.06 sys + 39.70 cusr 25.82 csys = 71.39 CPU)\n>>\n>> All tests pass on master.\n>\n> Thank you for doing this. 10 times slower is probably not worth\n> following up (though absolute numbers still look amazing, you have\n> some beefy machine there).\n\nThanks, but it's not too impressive: Xeon E3-1231 v3, Crucial BX100 SSD, \n8GB RAM. I wonder how much faster a brand-new CPU with more RAM and a \nPCIe SSD would be..\n\nRené\n\n"},{"id":"304988","messageId":"20161027204129.GA21619@starla","threadId":"44329","inReplyTo":"alpine.DEB.2.20.1610191049040.3847@virtualbox","subject":"Re: Drastic jump in the time required for the test suite","fromName":"Eric Wong","fromEmail":"e@80x24.org","sentAt":"2016-10-27T20:41:29Z","receivedAt":"2016-10-27T20:43:28Z","isPatch":false,"sender":{"key":"e@80x24.org","avatar":null},"body":"Johannes Schindelin wrote:\n> I know you are a fan of testing things thoroughly in the test suite, but I\n> have to say that it is getting out of hand, in particular due to our\n> over-use of shell script idioms (which really only run fast on Linux, not\n> a good idea for a portable software).\n\nHow much effort would it take to optimize a /bin/sh?\n\nWould replacing uses of fork+execve posix_spawn be fast and\nportable enough?\n\nEven on Linux, performance sucks for me. I've been hoping dash\ncan use posix_spawn (or using vfork directly) to see if that can\nhelp things.\n\nThat won't help with subshells, though...\n\n(I'm back to using a Centrino laptop from 2005)\n"},{"id":"305044","messageId":"CACsJy8ABaHxhrWke3Vu9Z9FSc5GC1LmupHRu4yS6=SFcp6eVHg@mail.gmail.com","threadId":"44329","inReplyTo":"20161027204129.GA21619@starla","subject":"Re: Drastic jump in the time required for the test suite","fromName":"Duy Nguyen","fromEmail":"pclouds@gmail.com","sentAt":"2016-10-28T06:38:32Z","receivedAt":"2016-10-28T06:39:09Z","isPatch":false,"sender":{"key":"pclouds@gmail.com","avatar":"https://avatars.githubusercontent.com/u/720?v=4"},"body":"On Fri, Oct 28, 2016 at 3:41 AM, Eric Wong wrote:\n> Johannes Schindelin wrote:\n>> I know you are a fan of testing things thoroughly in the test suite, but I\n>> have to say that it is getting out of hand, in particular due to our\n>> over-use of shell script idioms (which really only run fast on Linux, not\n>> a good idea for a portable software).\n>\n> How much effort would it take to optimize a /bin/sh?\n>\n> Would replacing uses of fork+execve posix_spawn be fast and\n> portable enough?\n>\n> Even on Linux, performance sucks for me. I've been hoping dash\n> can use posix_spawn (or using vfork directly) to see if that can\n> help things.\n\nBusybox hush uses vfork.on no-mmu builds. You could try it out. I\ndon't know how complete it is though.\n-- \nDuy\n"}]}