{"thread":{"id":"24700","subject":"[RFC/PATCH] WIP: Report intra-test progress with TAP subtests","startedAt":"2010-08-10T20:57:09Z","lastAt":"2010-08-11T16:41:52Z","messageCount":7,"participants":["Ævar Arnfjörð Bjarmason","Jonathan Nieder","Johannes Sixt"],"isPatch":true,"patchVersion":1,"patchTotal":null},"messages":[{"id":"147686","messageId":"1281473829-2102-1-git-send-email-avarab@gmail.com","threadId":"24700","inReplyTo":null,"subject":"[RFC/PATCH] WIP: Report intra-test progress with TAP subtests","fromName":"Ævar Arnfjörð Bjarmason","fromEmail":"avarab@gmail.com","sentAt":"2010-08-10T20:57:09Z","receivedAt":"2010-08-10T20:57:09Z","isPatch":true,"sender":{"key":"avarab@gmail.com","avatar":"https://avatars.githubusercontent.com/u/45301?v=4"},"body":"It can be a PITA to debug Git's tests. They're a maze of chained &&'s,\nand if one bit fails it can be hard to find out what that bit is.\n\nAs I mentioned in the comments for the \"user friendly alterantives to\n-d -f..\" series we could do this with TAP subtests:\n\n $ perl -MTest::More=no_plan -E '\n subtest \"A git test\" => sub {\n pass(\"doing test -f file\");\n pass(\"git commit ...\");\n pass(\"test_tick...\");\n done_testing();\n } for 1 .. 2\n '\n ok 1 - doing test -f file\n ok 2 - git commit ...\n ok 3 - test_tick...\n 1..3\n ok 1 - A git test\n ok 1 - doing test -f file\n ok 2 - git commit ...\n ok 3 - test_tick...\n 1..3\n ok 2 - A git test\n 1..2\n\nHere's an attempt at that, I've convented test_commit, test_merge and\ntest_cmp to report intra-test progress. The only problem is that it\ndoesn't quite work.\n\nIt works lik this:\n\n $ ./t0100-previous.sh --verbose 2>&1 | ack '(?:^\\s*ok|^\\s*not ok|\\d\\.\\.\\d)'\n ok 1 - test_commit file: message: contents\n 1..1\n ok 1 - branch -d @{-1}\n ok 2 - branch -d @{-12} when there is not enough switches yet\n ok 3 - test_commit file: message: contents\n ok 3 - test_commit file: message: contents\n 1..2\n ok 3 - merge @{-1}\n ok 4 - merge @{-1} when there is not enough switches yet\n 1..4\n\nBut the problem is that the subtest code is evaluated in the context of the test itself:\n\n\teval >&3 2>&4 \"$1\"\n\nSo when you run it you'll just get:\n\n $ ./t0100-previous.sh\n 1..1\n ok 1 - branch -d @{-1}\n ok 2 - branch -d @{-12} when there is not enough switches yet\n 1..2\n ok 3 - merge @{-1}\n ok 4 - merge @{-1} when there is not enough switches yet\n # passed all 4 test(s)\n 1..4\n\nIs there some filedescriptor saving/redirection magic I can do within\nthe subtest code to print things to the *real* stdout and stderr, not\nthe new file descriptors Git has aliased stdout/stderr to in the eval?\n\nAnother way to to it would be to buffer up the subtest output in a\nshell variable and spew it out all at once when the whole test\nfinishes, but then it would be out of context with the --verbose\noutput, and it'd be ugly.\n---\n t/test-lib.sh | 66 +++++++++++++++++++++++++++++++++++++++++++++++++-------\n 1 files changed, 57 insertions(+), 9 deletions(-)\n\ndiff --git a/t/test-lib.sh b/t/test-lib.sh\nindex 4e73fff..2380cb9 100644\n--- a/t/test-lib.sh\n+++ b/t/test-lib.sh\n@@ -208,6 +208,11 @@ test_success=0\n \n test_external_has_tap=0\n \n+# subtest state\n+in_subtest=\n+subtest_count=0\n+tap_prefix=\n+\n die () {\n \tcode=$?\n \tif test -n \"$GIT_EXIT_OK\"\n@@ -290,20 +295,38 @@ test_tick () {\n \n test_commit () {\n \tfile=${2:-\"$1.t\"}\n-\techo \"${3-$1}\" > \"$file\" &&\n-\tgit add \"$file\" &&\n-\ttest_tick &&\n-\tgit commit -m \"$1\" &&\n-\tgit tag \"$1\"\n+\tsubtest_count=$(($subtest_count + 1))\n+\n+\tif echo \"${3-$1}\" > \"$file\" &&\n+\t\tgit add \"$file\" &&\n+\t\ttest_tick &&\n+\t\tgit commit -m \"$1\" &&\n+\t\tgit tag \"$1\"\n+\tthen\n+\t\ttest_ok_ \"test_commit file:<$file> message:<$1> contents<${3-$1}>\"\n+\t\ttrue\n+\telse\n+\t\ttest_failure_ \"test_commit file:<$file> message:<$1> contents<${3-$1}>\"\n+\t\ttrue\n+\tfi\n }\n \n # Call test_merge with the arguments \" \", where \n # can be a tag pointing to the commit-to-merge.\n \n test_merge () {\n-\ttest_tick &&\n-\tgit merge -m \"$1\" \"$2\" &&\n-\tgit tag \"$1\"\n+\n+\tsubtest_count=$(($subtest_count + 1))\n+\tif test_tick &&\n+\t\tgit merge -m \"$1\" \"$2\" &&\n+\t\tgit tag \"$1\"\n+\tthen\n+\t\ttest_ok_ \"test_merge: file<$2> message<$1> tag:<$1>\"\n+\t\ttrue\n+\telse\n+\t\ttest_failure_ \"test_merge: file<$2> message<$1> tag:<$1>\"\n+\t\tfalse\n+\tfi\n }\n \n # This function helps systems where core.filemode=false is set.\n@@ -353,7 +376,7 @@ test_have_prereq () {\n \n test_ok_ () {\n \ttest_success=$(($test_success + 1))\n-\tsay_color \"\" \"ok $test_count - $@\"\n+\tsay_color \"\" \"${tap_prefix}ok $test_count - $@\"\n }\n \n test_failure_ () {\n@@ -380,9 +403,25 @@ test_debug () {\n \n test_run_ () {\n \ttest_cleanup=:\n+\n+\t# Run the test in a subtest scope\n+\tin_subtest=1\n+\tsubtest_count=0\n+\ttap_prefix=' '\n \teval >&3 2>&4 \"$1\"\n+\tin_subtest=\n+\n \teval_ret=$?\n \teval >&3 2>&4 \"$test_cleanup\"\n+\n+\t# Report the subtest plan\n+\tif test $subtest_count -gt 0\n+\tthen\n+\t\tsay \"${tap_prefix}1..$subtest_count\"\n+\t\tsubtest_count=0\n+\tfi\n+\ttap_prefix=\n+\n \tif test \"$verbose\" = \"t\" && test -n \"$HARNESS_ACTIVE\"; then\n \t\techo \"\"\n \tfi\n@@ -602,6 +641,15 @@ test_might_fail () {\n \n test_cmp() {\n \t$GIT_TEST_CMP \"$@\"\n+\tsubtest_count=$(($subtest_count + 1))\n+\tif test \"$?\" = 0\n+\tthen\n+\t\ttest_ok_ \"test_cmp '$@'\"\n+\t\ttrue\n+\telse\n+\t\ttest_failure_ \"test_cmp '$@'\"\n+\t\tfalse\n+\tfi\n }\n \n # This function can be used to schedule some commands to be run\n-- \n1.7.2.1.295.gd03d\n"},{"id":"147706","messageId":"20100811004425.GI2099@burratino","threadId":"24700","inReplyTo":"1281473829-2102-1-git-send-email-avarab@gmail.com","subject":"Re: [RFC/PATCH] WIP: Report intra-test progress with TAP subtests","fromName":"Jonathan Nieder","fromEmail":"jrnieder@gmail.com","sentAt":"2010-08-11T00:44:25Z","receivedAt":"2010-08-11T00:44:25Z","isPatch":true,"sender":{"key":"jrnieder@gmail.com","avatar":"https://avatars.githubusercontent.com/u/281595?v=4"},"body":"Hi Ævar,\n\nÆvar Arnfjörð Bjarmason wrote:\n\n> ok 1 - A git test\n> ok 1 - doing test -f file\n> ok 2 - git commit ...\n> ok 3 - test_tick...\n> 1..3\n> ok 2 - A git test\n> 1..2\n> \n> Here's an attempt at that, I've convented test_commit, test_merge and\n> test_cmp to report intra-test progress.\n\nWhat if a test uses none of those commands?\n\nThe ultimate conclusion of such an approach would be to use\nreplacements for common commands like “git” and “cd”, making tests a\nlot harder to read and write for the uninitiated.\n\nIf we get peeks where the infrastructure has a chance to provide\nthem, maybe it would be nice to allow explicitly inserting such\ncheckpoints, too? Like:\n\n\tmv init init2 &&\n\tcheckpoint &&\n\tgit config -f .gitmodules submodule.example.url \"$(pwd)/init2\" &&\n\tcheckpoint &&\n\tgit config --remove-section submodule.example &&\n\tcheckpoint &&\n\t[...]\n\nwhile debugging.\n\nHowever, I would rather see those inserted automatically.\nTwo ideas without code to back them up:\n\n1. Script parsing.\n\nYes, parsing shell command language is hard, but tests use only\na subset of it. In particular the &&-chaining means it might\nbe relatively easy to find where each command starts and ends.\n\nThe hard bits: “if”, “while”, and “for” flow control constructs.\n\nThe payoff of even partial progress in this would be very high,\nsince it should make static analysis of &&-chaining possible.\n\n2. Letting the shell trace for us.\n\nWhen tests fail, I generally use\n\n\tsh -x ./failing-test.sh -v -i\n\nand scroll back through the log to the important part.\n\nMaybe the test harness could automate that a little, by using\nset -x at the beginning and set +x at the end of each test.\n\nHope that helps,\nJonathan\n"},{"id":"147707","messageId":"AANLkTi=ygXFpRLR_Z7iEXX3THh+GT7P7X9o+NnaLajqs@mail.gmail.com","threadId":"24700","inReplyTo":"20100811004425.GI2099@burratino","subject":"Re: [RFC/PATCH] WIP: Report intra-test progress with TAP subtests","fromName":"Ævar Arnfjörð Bjarmason","fromEmail":"avarab@gmail.com","sentAt":"2010-08-11T00:55:49Z","receivedAt":"2010-08-11T00:55:49Z","isPatch":true,"sender":{"key":"avarab@gmail.com","avatar":"https://avatars.githubusercontent.com/u/45301?v=4"},"body":"On Wed, Aug 11, 2010 at 00:44, Jonathan Nieder wrote:\n> Hi Ævar,\n>\n> Ævar Arnfjörð Bjarmason wrote:\n>\n>>    ok 1 - A git test\n>>        ok 1 - doing test -f file\n>>        ok 2 - git commit ...\n>>        ok 3 - test_tick...\n>>        1..3\n>>    ok 2 - A git test\n>>    1..2\n>>\n>> Here's an attempt at that, I've convented test_commit, test_merge and\n>> test_cmp to report intra-test progress.\n>\n> What if a test uses none of those commands?\n\nThen it won't get any progress output.\n\n> The ultimate conclusion of such an approach would be to use\n> replacements for common commands like “git” and “cd”, making tests a\n> lot harder to read and write for the uninitiated.\n\nYes, but there's a middle ground here. We use a lot of utility\nfunctions in the tests, adding tracing to these makes it easier to see\nwhat's going on, especially in large tests.\n\n> If we get peeks where the infrastructure has a chance to provide\n> them, maybe it would be nice to allow explicitly inserting such\n> checkpoints, too?  Like:\n>\n>        mv init init2 &&\n>        checkpoint &&\n>        git config -f .gitmodules submodule.example.url \"$(pwd)/init2\" &&\n>        checkpoint &&\n>        git config --remove-section submodule.example &&\n>        checkpoint &&\n>        [...]\n>\n> while debugging.\n\nYeah. I was going to add something like that if I got this working.\n\n> However, I would rather see those inserted automatically.\n> Two ideas without code to back them up:\n>\n> 1. Script parsing.\n>\n> Yes, parsing shell command language is hard, but tests use only\n> a subset of it.  In particular the &&-chaining means it might\n> be relatively easy to find where each command starts and ends.\n>\n> The hard bits: “if”, “while”, and “for” flow control constructs.\n>\n> The payoff of even partial progress in this would be very high,\n> since it should make static analysis of &&-chaining possible.\n\nSounds like a good long term project, and shouldn't be so hard for the\nsimple case.\n\n> 2. Letting the shell trace for us.\n>\n> When tests fail, I generally use\n>\n>        sh -x ./failing-test.sh -v -i\n>\n> and scroll back through the log to the important part.\n>\n> Maybe the test harness could automate that a little, by using\n> set -x at the beginning and set +x at the end of each test.\n\nThe main use case for this for me is the smoke tester output, where\nyou won't get access to the original machine (without asking). Having\na few intra-test checkpoints helps you to see where things might have\ngone wrong.\n"},{"id":"147709","messageId":"20100811010412.GA2994@burratino","threadId":"24700","inReplyTo":"AANLkTi=ygXFpRLR_Z7iEXX3THh+GT7P7X9o+NnaLajqs@mail.gmail.com","subject":"Re: [RFC/PATCH] WIP: Report intra-test progress with TAP subtests","fromName":"Jonathan Nieder","fromEmail":"jrnieder@gmail.com","sentAt":"2010-08-11T01:04:12Z","receivedAt":"2010-08-11T01:04:12Z","isPatch":true,"sender":{"key":"jrnieder@gmail.com","avatar":"https://avatars.githubusercontent.com/u/281595?v=4"},"body":"Ævar Arnfjörð Bjarmason wrote:\n> On Wed, Aug 11, 2010 at 00:44, Jonathan Nieder wrote:\n\n>> Maybe the test harness could automate that a little, by using\n>> set -x at the beginning and set +x at the end of each test.\n>\n> The main use case for this for me is the smoke tester output, where\n> you won't get access to the original machine (without asking). Having\n> a few intra-test checkpoints helps you to see where things might have\n> gone wrong.\n\nI meant something like this:\n-- 8< --\ndiff --git a/t/test-lib.sh b/t/test-lib.sh\nindex e5523dd..a4bc358 100644\n--- a/t/test-lib.sh\n+++ b/t/test-lib.sh\n@@ -368,9 +368,11 @@ test_debug () {\n \n test_run_ () {\n \ttest_cleanup=:\n+\tset -x\n \teval >&3 2>&4 \"$1\"\n \teval_ret=$?\n \teval >&3 2>&4 \"$test_cleanup\"\n+\tset +x\n \tif test \"$verbose\" = \"t\" && test -n \"$HARNESS_ACTIVE\"; then\n \t\techo \"\"\n \tfi\n-- >8 --\n\nbut made optional and with output munged into parsable format by\nchanging PS4 (or \"set -T\" with a DEBUG trap, if that’s portable\nenough).\n"},{"id":"147718","messageId":"20100811052830.GA1355@burratino","threadId":"24700","inReplyTo":"1281473829-2102-1-git-send-email-avarab@gmail.com","subject":"Re: [RFC/PATCH] WIP: Report intra-test progress with TAP subtests","fromName":"Jonathan Nieder","fromEmail":"jrnieder@gmail.com","sentAt":"2010-08-11T05:28:30Z","receivedAt":"2010-08-11T05:28:30Z","isPatch":true,"sender":{"key":"jrnieder@gmail.com","avatar":"https://avatars.githubusercontent.com/u/281595?v=4"},"body":"Ævar Arnfjörð Bjarmason wrote:\n\n> Here's an attempt at that, I've convented test_commit, test_merge and\n> test_cmp to report intra-test progress. The only problem is that it\n> doesn't quite work.\n\nI forgot to say: thanks for the demonstration. This is neat stuff.\n\n> \teval >&3 2>&4 \"$1\"\n> \n> So when you run it you'll just get:\n> \n> $ ./t0100-previous.sh\n> 1..1\n> ok 1 - branch -d @{-1}\n> ok 2 - branch -d @{-12} when there is not enough switches yet\n> 1..2\n> ok 3 - merge @{-1}\n> ok 4 - merge @{-1} when there is not enough switches yet\n> # passed all 4 test(s)\n> 1..4\n> \n> Is there some filedescriptor saving/redirection magic I can do within\n> the subtest code to print things to the *real* stdout and stderr\n\nDescriptor 5 is a pass-through for stdout: see v0.99.5~24^2~4\n(Trapping exit in tests, 2005-08-10).\n\nDo you need a pass-through for stderr, too, or was that theoretical?\n\n> @@ -290,20 +295,38 @@ test_tick () {\n> \n> test_commit () {\n> \tfile=${2:-\"$1.t\"}\n> -\techo \"${3-$1}\" > \"$file\" &&\n> -\tgit add \"$file\" &&\n> -\ttest_tick &&\n> -\tgit commit -m \"$1\" &&\n> -\tgit tag \"$1\"\n> +\tsubtest_count=$(($subtest_count + 1))\n> +\n> +\tif echo \"${3-$1}\" > \"$file\" &&\n> +\t\tgit add \"$file\" &&\n> +\t\ttest_tick &&\n> +\t\tgit commit -m \"$1\" &&\n> +\t\tgit tag \"$1\"\n> +\tthen\n> +\t\ttest_ok_ \"test_commit file:<$file> message:<$1> contents<${3-$1}>\"\n> +\t\ttrue\n> +\telse\n> +\t\ttest_failure_ \"test_commit file:<$file> message:<$1> contents<${3-$1}>\"\n> +\t\ttrue\n> +\tfi\n\nThis would make the test continue after the subtest, right? Is that\nintended?\n"},{"id":"147719","messageId":"4C6246D7.6090704@viscovery.net","threadId":"24700","inReplyTo":"20100811010412.GA2994@burratino","subject":"Re: [RFC/PATCH] WIP: Report intra-test progress with TAP subtests","fromName":"Johannes Sixt","fromEmail":"j.sixt@viscovery.net","sentAt":"2010-08-11T06:44:39Z","receivedAt":"2010-08-11T06:44:39Z","isPatch":true,"sender":{"key":"j6t@kdbg.org","avatar":"https://avatars.githubusercontent.com/u/14810926?v=4"},"body":"Am 8/11/2010 3:04, schrieb Jonathan Nieder:\n> I meant something like this:\n> -- 8< --\n> diff --git a/t/test-lib.sh b/t/test-lib.sh\n> index e5523dd..a4bc358 100644\n> --- a/t/test-lib.sh\n> +++ b/t/test-lib.sh\n> @@ -368,9 +368,11 @@ test_debug () {\n> \n> test_run_ () {\n> \ttest_cleanup=:\n> +\tset -x\n> \teval >&3 2>&4 \"$1\"\n> \teval_ret=$?\n> \teval >&3 2>&4 \"$test_cleanup\"\n> +\tset +x\n> \tif test \"$verbose\" = \"t\" && test -n \"$HARNESS_ACTIVE\"; then\n> \t\techo \"\"\n> \tfi\n> -- >8 --\n\nHeh. I use something like this in my private build. It breaks a number of\ntests due to additional output from test_must_fail invocations. I work\naround it by adding 'set +x' inside the test case code. See\n\nhttp://repo.or.cz/w/git/mingw/j6t.git/commitdiff/3943fd12f69da58937ac67a20be440f0ed532f18\n\n-- Hannes\n"},{"id":"147797","messageId":"AANLkTikphSj-tLRZwJ3MPrhYtPObZv2kJ0z4iJLJF=Gy@mail.gmail.com","threadId":"24700","inReplyTo":"20100811052830.GA1355@burratino","subject":"Re: [RFC/PATCH] WIP: Report intra-test progress with TAP subtests","fromName":"Ævar Arnfjörð Bjarmason","fromEmail":"avarab@gmail.com","sentAt":"2010-08-11T16:41:52Z","receivedAt":"2010-08-11T16:41:52Z","isPatch":true,"sender":{"key":"avarab@gmail.com","avatar":"https://avatars.githubusercontent.com/u/45301?v=4"},"body":"On Wed, Aug 11, 2010 at 05:28, Jonathan Nieder wrote:\n> Ævar Arnfjörð Bjarmason wrote:\n>\n>> Here's an attempt at that, I've convented test_commit, test_merge and\n>> test_cmp to report intra-test progress. The only problem is that it\n>> doesn't quite work.\n>\n> I forgot to say: thanks for the demonstration.  This is neat stuff.\n>\n>>       eval >&3 2>&4 \"$1\"\n>>\n>> So when you run it you'll just get:\n>>\n>>     $ ./t0100-previous.sh\n>>         1..1\n>>     ok 1 - branch -d @{-1}\n>>     ok 2 - branch -d @{-12} when there is not enough switches yet\n>>         1..2\n>>     ok 3 - merge @{-1}\n>>     ok 4 - merge @{-1} when there is not enough switches yet\n>>     # passed all 4 test(s)\n>>     1..4\n>>\n>> Is there some filedescriptor saving/redirection magic I can do within\n>> the subtest code to print things to the *real* stdout and stderr\n>\n> Descriptor 5 is a pass-through for stdout: see v0.99.5~24^2~4\n> (Trapping exit in tests, 2005-08-10).\n>\n> Do you need a pass-through for stderr, too, or was that theoretical?\n\nNope, thanks. Using >&5 works.\n\n>> @@ -290,20 +295,38 @@ test_tick () {\n>>\n>>  test_commit () {\n>>       file=${2:-\"$1.t\"}\n>> -     echo \"${3-$1}\" > \"$file\" &&\n>> -     git add \"$file\" &&\n>> -     test_tick &&\n>> -     git commit -m \"$1\" &&\n>> -     git tag \"$1\"\n>> +     subtest_count=$(($subtest_count + 1))\n>> +\n>> +     if echo \"${3-$1}\" > \"$file\" &&\n>> +             git add \"$file\" &&\n>> +             test_tick &&\n>> +             git commit -m \"$1\" &&\n>> +             git tag \"$1\"\n>> +     then\n>> +             test_ok_ \"test_commit file:<$file> message:<$1> contents<${3-$1}>\"\n>> +             true\n>> +     else\n>> +             test_failure_ \"test_commit file:<$file> message:<$1> contents<${3-$1}>\"\n>> +             true\n>> +     fi\n>\n> This would make the test continue after the subtest, right?  Is that\n> intended?\n\nNo, should be return 0/1. Changed that in my working branch.\n\nI'm going to drop this for a while until my pending patches to test\nstuff get into pu. But initial experiments with using >&5 everywhere\nfor test progress are promising:\n\n http://github.com/avar/git/tree/test-intra-progress-using-tap-subtests-v2\n"}]}