{"thread":{"id":"37703","subject":"[PATCH 0/3] \"-x\" tracing option for tests","startedAt":"2014-10-10T06:06:37Z","lastAt":"2014-10-14T13:44:15Z","messageCount":26,"participants":["Jeff King","Jonathan Nieder","Junio C Hamano","Michael Haggerty"],"isPatch":true,"patchVersion":1,"patchTotal":3},"messages":[{"id":"250465","messageId":"20141010060636.GA15057@peff.net","threadId":"37703","inReplyTo":null,"subject":"[PATCH 0/3] \"-x\" tracing option for tests","fromName":"Jeff King","fromEmail":"peff@peff.net","sentAt":"2014-10-10T06:06:37Z","receivedAt":"2014-10-10T06:06:37Z","isPatch":true,"sender":{"key":"peff@peff.net","avatar":"https://avatars.githubusercontent.com/u/45925?v=4"},"body":"These patches are pulled out of the prune-mtime series I posted\nearlier[1]. The discussion veered off and there's no reason that the two\ntopics need to be part of the same series.\n\nThe first patch is the same cleanup as before.\n\nThe second one uses Michael's suggested \"verbose\" function, like:\n\n  $ verbose test 1 = 2\n  command failed: 'test' '1' '=' '2'\n\n(you can see that I used rev-parse's --sq-quote, which is a little eager\nto use quotes where they are not needed. I wonder if we should teach it\nto produce prettier output when there is nothing outside of\n[A-Za-z0-9=] or similar).\n\nThe third one is a cleanup of the \"set -x\" patch I posted earlier. I\nmade the implementation a little less gross, the output a little\ncleaner, and wired it up to \"-x\". I think it's clean enough and useful\nenough to add to our bag of test-debugging tricks.\n\n  [1/3]: t5304: use test_path_is_* instead of \"test -f\"\n  [2/3]: t5304: use helper to report failure of \"test foo = bar\"\n  [3/3]: test-lib.sh: support -x option for shell-tracing\n\n-Peff\n\n[1] http://thread.gmane.org/gmane.comp.version-control.git/257850/focus=257859\n"},{"id":"250466","messageId":"20141010060700.GA15277@peff.net","threadId":"37703","inReplyTo":"20141010060636.GA15057@peff.net","subject":"[PATCH 1/3] t5304: use test_path_is_* instead of \"test -f\"","fromName":"Jeff King","fromEmail":"peff@peff.net","sentAt":"2014-10-10T06:07:00Z","receivedAt":"2014-10-10T06:07:00Z","isPatch":true,"sender":{"key":"peff@peff.net","avatar":"https://avatars.githubusercontent.com/u/45925?v=4"},"body":"This is slightly more robust (checking \"! test -f\" would not\nnotice a directory of the same name, though that is not\nlikely to happen here). It also makes debugging easier, as\nthe test script will output a message on failure.\n\nSigned-off-by: Jeff King <peff@peff.net>\n---\n t/t5304-prune.sh | 46 +++++++++++++++++++++++-----------------------\n 1 file changed, 23 insertions(+), 23 deletions(-)\n\ndiff --git a/t/t5304-prune.sh b/t/t5304-prune.sh\nindex 01c6a3f..b0ffb05 100755\n--- a/t/t5304-prune.sh\n+++ b/t/t5304-prune.sh\n@@ -14,7 +14,7 @@ add_blob() {\n \tBLOB=$(echo aleph_0 | git hash-object -w --stdin) &&\n \tBLOB_FILE=.git/objects/$(echo $BLOB | sed \"s/^../&\\//\") &&\n \ttest $((1 + $before)) = $(git count-objects | sed \"s/ .*//\") &&\n-\ttest -f $BLOB_FILE &&\n+\ttest_path_is_file $BLOB_FILE &&\n \ttest-chmtime =+0 $BLOB_FILE\n }\n \n@@ -35,9 +35,9 @@ test_expect_success 'prune stale packs' '\n \t: > .git/objects/tmp_2.pack &&\n \ttest-chmtime =-86501 .git/objects/tmp_1.pack &&\n \tgit prune --expire 1.day &&\n-\ttest -f $orig_pack &&\n-\ttest -f .git/objects/tmp_2.pack &&\n-\t! test -f .git/objects/tmp_1.pack\n+\ttest_path_is_file $orig_pack &&\n+\ttest_path_is_file .git/objects/tmp_2.pack &&\n+\ttest_path_is_missing .git/objects/tmp_1.pack\n \n '\n \n@@ -46,11 +46,11 @@ test_expect_success 'prune --expire' '\n \tadd_blob &&\n \tgit prune --expire=1.hour.ago &&\n \ttest $((1 + $before)) = $(git count-objects | sed \"s/ .*//\") &&\n-\ttest -f $BLOB_FILE &&\n+\ttest_path_is_file $BLOB_FILE &&\n \ttest-chmtime =-86500 $BLOB_FILE &&\n \tgit prune --expire 1.day &&\n \ttest $before = $(git count-objects | sed \"s/ .*//\") &&\n-\t! test -f $BLOB_FILE\n+\ttest_path_is_missing $BLOB_FILE\n \n '\n \n@@ -60,11 +60,11 @@ test_expect_success 'gc: implicit prune --expire' '\n \ttest-chmtime =-$((2*$week-30)) $BLOB_FILE &&\n \tgit gc &&\n \ttest $((1 + $before)) = $(git count-objects | sed \"s/ .*//\") &&\n-\ttest -f $BLOB_FILE &&\n+\ttest_path_is_file $BLOB_FILE &&\n \ttest-chmtime =-$((2*$week+1)) $BLOB_FILE &&\n \tgit gc &&\n \ttest $before = $(git count-objects | sed \"s/ .*//\") &&\n-\t! test -f $BLOB_FILE\n+\ttest_path_is_missing $BLOB_FILE\n \n '\n \n@@ -110,7 +110,7 @@ test_expect_success 'prune: do not prune detached HEAD with no reflog' '\n \tgit commit --allow-empty -m \"detached commit\" &&\n \t# verify that there is no reflogs\n \t# (should be removed and disabled by previous test)\n-\ttest ! -e .git/logs &&\n+\ttest_path_is_missing .git/logs &&\n \tgit prune -n >prune_actual &&\n \t: >prune_expected &&\n \ttest_cmp prune_actual prune_expected\n@@ -145,7 +145,7 @@ test_expect_success 'gc --no-prune' '\n \tgit config gc.pruneExpire 2.days.ago &&\n \tgit gc --no-prune &&\n \ttest 1 = $(git count-objects | sed \"s/ .*//\") &&\n-\ttest -f $BLOB_FILE\n+\ttest_path_is_file $BLOB_FILE\n \n '\n \n@@ -153,10 +153,10 @@ test_expect_success 'gc respects gc.pruneExpire' '\n \n \tgit config gc.pruneExpire 5002.days.ago &&\n \tgit gc &&\n-\ttest -f $BLOB_FILE &&\n+\ttest_path_is_file $BLOB_FILE &&\n \tgit config gc.pruneExpire 5000.days.ago &&\n \tgit gc &&\n-\ttest ! -f $BLOB_FILE\n+\ttest_path_is_missing $BLOB_FILE\n \n '\n \n@@ -165,9 +165,9 @@ test_expect_success 'gc --prune=<date>' '\n \tadd_blob &&\n \ttest-chmtime =-$((5001*$day)) $BLOB_FILE &&\n \tgit gc --prune=5002.days.ago &&\n-\ttest -f $BLOB_FILE &&\n+\ttest_path_is_file $BLOB_FILE &&\n \tgit gc --prune=5000.days.ago &&\n-\ttest ! -f $BLOB_FILE\n+\ttest_path_is_missing $BLOB_FILE\n \n '\n \n@@ -175,9 +175,9 @@ test_expect_success 'gc --prune=never' '\n \n \tadd_blob &&\n \tgit gc --prune=never &&\n-\ttest -f $BLOB_FILE &&\n+\ttest_path_is_file $BLOB_FILE &&\n \tgit gc --prune=now &&\n-\ttest ! -f $BLOB_FILE\n+\ttest_path_is_missing $BLOB_FILE\n \n '\n \n@@ -186,10 +186,10 @@ test_expect_success 'gc respects gc.pruneExpire=never' '\n \tgit config gc.pruneExpire never &&\n \tadd_blob &&\n \tgit gc &&\n-\ttest -f $BLOB_FILE &&\n+\ttest_path_is_file $BLOB_FILE &&\n \tgit config gc.pruneExpire now &&\n \tgit gc &&\n-\ttest ! -f $BLOB_FILE\n+\ttest_path_is_missing $BLOB_FILE\n \n '\n \n@@ -197,9 +197,9 @@ test_expect_success 'prune --expire=never' '\n \n \tadd_blob &&\n \tgit prune --expire=never &&\n-\ttest -f $BLOB_FILE &&\n+\ttest_path_is_file $BLOB_FILE &&\n \tgit prune &&\n-\ttest ! -f $BLOB_FILE\n+\ttest_path_is_missing $BLOB_FILE\n \n '\n \n@@ -210,10 +210,10 @@ test_expect_success 'gc: prune old objects after local clone' '\n \t(\n \t\tcd aclone &&\n \t\ttest 1 = $(git count-objects | sed \"s/ .*//\") &&\n-\t\ttest -f $BLOB_FILE &&\n+\t\ttest_path_is_file $BLOB_FILE &&\n \t\tgit gc --prune &&\n \t\ttest 0 = $(git count-objects | sed \"s/ .*//\") &&\n-\t\t! test -f $BLOB_FILE\n+\t\ttest_path_is_missing $BLOB_FILE\n \t)\n '\n \n@@ -250,7 +250,7 @@ test_expect_success 'prune .git/shallow' '\n \tgrep $SHA1 .git/shallow &&\n \tgrep $SHA1 out &&\n \tgit prune &&\n-\t! test -f .git/shallow\n+\ttest_path_is_missing .git/shallow\n '\n \n test_done\n-- \n2.1.2.596.g7379948\n"},{"id":"250467","messageId":"20141010061114.GB15277@peff.net","threadId":"37703","inReplyTo":"20141010060636.GA15057@peff.net","subject":"[PATCH 2/3] t5304: use helper to report failure of \"test foo = bar\"","fromName":"Jeff King","fromEmail":"peff@peff.net","sentAt":"2014-10-10T06:11:14Z","receivedAt":"2014-10-10T06:11:14Z","isPatch":true,"sender":{"key":"peff@peff.net","avatar":"https://avatars.githubusercontent.com/u/45925?v=4"},"body":"For small outputs, we sometimes use:\n\n  test \"$(some_cmd)\" = \"something we expect\"\n\ninstead of a full test_cmp. The downside of this is that\nwhen it fails, there is no output at all from the script.\nLet's introduce a small helper to make tests easier to\ndebug.\n\nSigned-off-by: Jeff King <peff@peff.net>\n---\nI kind of like the elegance of this, but I'd also be OK with dropping\nit. The solution from the third patch does the same thing. And while the\noutput isn't quite as nice, it magically works for all existing tests,\nwithout having to convert them to use verbose().\n\nI wondered if there was any problem with defining a function with the\nsame name as a variable ($verbose). A few weeks ago, I would have said\nthey were completely different namespaces, but after seeing the\nshellshock vulnerability I am not so sure. :) This seems to work fine\nin bash and dash, but maybe there is some more obscure shell that would\nnot like it?\n\nTechnically this function is the opposite of test_must_fail. We could\ncall it test_must_succeed, but that is a little wordy for my taste (I\nactually considered calling it just v() if we are going to use it a\nlot, but that may be going too far).\n\n t/t5304-prune.sh        | 16 ++++++++--------\n t/test-lib-functions.sh |  9 +++++++++\n 2 files changed, 17 insertions(+), 8 deletions(-)\n\ndiff --git a/t/t5304-prune.sh b/t/t5304-prune.sh\nindex b0ffb05..e32e46d 100755\n--- a/t/t5304-prune.sh\n+++ b/t/t5304-prune.sh\n@@ -13,7 +13,7 @@ add_blob() {\n \tbefore=$(git count-objects | sed \"s/ .*//\") &&\n \tBLOB=$(echo aleph_0 | git hash-object -w --stdin) &&\n \tBLOB_FILE=.git/objects/$(echo $BLOB | sed \"s/^../&\\//\") &&\n-\ttest $((1 + $before)) = $(git count-objects | sed \"s/ .*//\") &&\n+\tverbose test $((1 + $before)) = $(git count-objects | sed \"s/ .*//\") &&\n \ttest_path_is_file $BLOB_FILE &&\n \ttest-chmtime =+0 $BLOB_FILE\n }\n@@ -45,11 +45,11 @@ test_expect_success 'prune --expire' '\n \n \tadd_blob &&\n \tgit prune --expire=1.hour.ago &&\n-\ttest $((1 + $before)) = $(git count-objects | sed \"s/ .*//\") &&\n+\tverbose test $((1 + $before)) = $(git count-objects | sed \"s/ .*//\") &&\n \ttest_path_is_file $BLOB_FILE &&\n \ttest-chmtime =-86500 $BLOB_FILE &&\n \tgit prune --expire 1.day &&\n-\ttest $before = $(git count-objects | sed \"s/ .*//\") &&\n+\tverbose test $before = $(git count-objects | sed \"s/ .*//\") &&\n \ttest_path_is_missing $BLOB_FILE\n \n '\n@@ -59,11 +59,11 @@ test_expect_success 'gc: implicit prune --expire' '\n \tadd_blob &&\n \ttest-chmtime =-$((2*$week-30)) $BLOB_FILE &&\n \tgit gc &&\n-\ttest $((1 + $before)) = $(git count-objects | sed \"s/ .*//\") &&\n+\tverbose test $((1 + $before)) = $(git count-objects | sed \"s/ .*//\") &&\n \ttest_path_is_file $BLOB_FILE &&\n \ttest-chmtime =-$((2*$week+1)) $BLOB_FILE &&\n \tgit gc &&\n-\ttest $before = $(git count-objects | sed \"s/ .*//\") &&\n+\tverbose test $before = $(git count-objects | sed \"s/ .*//\") &&\n \ttest_path_is_missing $BLOB_FILE\n \n '\n@@ -144,7 +144,7 @@ test_expect_success 'gc --no-prune' '\n \ttest-chmtime =-$((5001*$day)) $BLOB_FILE &&\n \tgit config gc.pruneExpire 2.days.ago &&\n \tgit gc --no-prune &&\n-\ttest 1 = $(git count-objects | sed \"s/ .*//\") &&\n+\tverbose test 1 = $(git count-objects | sed \"s/ .*//\") &&\n \ttest_path_is_file $BLOB_FILE\n \n '\n@@ -209,10 +209,10 @@ test_expect_success 'gc: prune old objects after local clone' '\n \tgit clone --no-hardlinks . aclone &&\n \t(\n \t\tcd aclone &&\n-\t\ttest 1 = $(git count-objects | sed \"s/ .*//\") &&\n+\t\tverbose test 1 = $(git count-objects | sed \"s/ .*//\") &&\n \t\ttest_path_is_file $BLOB_FILE &&\n \t\tgit gc --prune &&\n-\t\ttest 0 = $(git count-objects | sed \"s/ .*//\") &&\n+\t\tverbose test 0 = $(git count-objects | sed \"s/ .*//\") &&\n \t\ttest_path_is_missing $BLOB_FILE\n \t)\n '\ndiff --git a/t/test-lib-functions.sh b/t/test-lib-functions.sh\nindex dafd6ad..b7957b8 100644\n--- a/t/test-lib-functions.sh\n+++ b/t/test-lib-functions.sh\n@@ -634,6 +634,15 @@ test_cmp_bin() {\n \tcmp \"$@\"\n }\n \n+# Call any command \"$@\" but be more verbose about its\n+# failure. This is handy for commands like \"test\" which do\n+# not output anything when they fail.\n+verbose () {\n+\t\"$@\" && return 0\n+\techo >&2 \"command failed: $(git rev-parse --sq-quote \"$@\")\"\n+\treturn 1\n+}\n+\n # Check if the file expected to be empty is indeed empty, and barfs\n # otherwise.\n \n-- \n2.1.2.596.g7379948\n"},{"id":"250468","messageId":"20141010061355.GC15277@peff.net","threadId":"37703","inReplyTo":"20141010060636.GA15057@peff.net","subject":"[PATCH 3/3] test-lib.sh: support -x option for shell-tracing","fromName":"Jeff King","fromEmail":"peff@peff.net","sentAt":"2014-10-10T06:13:56Z","receivedAt":"2014-10-10T06:13:56Z","isPatch":true,"sender":{"key":"peff@peff.net","avatar":"https://avatars.githubusercontent.com/u/45925?v=4"},"body":"Usually running a test under \"-v\" makes it clear which\ncommand is failing. However, sometimes it can be useful to\nalso see a complete trace of the shell commands being run in\nthe test. You can do so without any support from the test\nsuite by running \"sh -x tXXXX-foo.sh\". However, this\nproduces quite a large bit of output, as we see a trace of\nthe entire test suite.\n\nThis patch instead introduces a \"-x\" option to the test\nscripts (i.e., \"./tXXXX-foo.sh -x\"). When enabled, this\nturns on \"set -x\" only for the tests themselves. This can\nstill be a bit verbose, but should keep things to a more\nmanageable level. You can even use \"--verbose-only\" to see\nthe trace only for a specific test.\n\nThe implementation is a little invasive. We turn on the \"set\n-x\" inside the \"eval\" of the test code. This lets the eval\nitself avoid being reported in the trace (which would be\nlong, and redundant with the verbose listing we already\nshowed). And then after the eval runs, we do some trickery\nwith stderr to avoid showing the \"set +x\" to the user.\n\nWe also show traces for test_cleanup functions (since they\ncan impact the test outcome, too). However, we do avoid\nrunning the noop \":\" cleanup (the default if the test does\nnot use test_cleanup at all), as it creates unnecessary\nnoise in the \"set -x\" output.\n\nSigned-off-by: Jeff King <peff@peff.net>\n---\nHaving finally figured out how to drop the \"set +x\" from the output, I\nhave noticed that I kind of liked the \"test_eval_ret=$?\" part of the\ntrace (which is now gone, too), because it pretty explicitly tells you\nthat the last traced command failed. But now that it has been silenced,\nthere's no reason we couldn't add back in our own output to make it more\nclear.\n\n t/README      |  4 ++++\n t/test-lib.sh | 34 ++++++++++++++++++++++++++++++----\n 2 files changed, 34 insertions(+), 4 deletions(-)\n\ndiff --git a/t/README b/t/README\nindex 52c77ae..38cb078 100644\n--- a/t/README\n+++ b/t/README\n@@ -82,6 +82,10 @@ appropriately before running \"make\".\n \tnumbers matching <pattern>.  The number matched against is\n \tsimply the running count of the test within the file.\n \n+-x::\n+\tTurn on shell tracing (i.e., `set -x`) during the tests\n+\tthemselves. Implies `--verbose`.\n+\n -d::\n --debug::\n \tThis may help the person who is developing a new test.\ndiff --git a/t/test-lib.sh b/t/test-lib.sh\nindex 82095e3..a60ec75 100644\n--- a/t/test-lib.sh\n+++ b/t/test-lib.sh\n@@ -187,6 +187,8 @@ export _x05 _x40 _z40 LF\n \t) &&\n \tcolor=t\n \n+test_eval_start_=\n+test_eval_end_=\n while test \"$#\" -ne 0\n do\n \tcase \"$1\" in\n@@ -233,6 +235,11 @@ do\n \t--root=*)\n \t\troot=$(expr \"z$1\" : 'z[^=]*=\\(.*\\)')\n \t\tshift ;;\n+\t-x)\n+\t\ttest_eval_start_='set -x'\n+\t\ttest_eval_end_='set +x'\n+\t\tverbose=t\n+\t\tshift ;;\n \t*)\n \t\techo \"error: unknown test option '$1'\" >&2; exit 1 ;;\n \tesac\n@@ -517,10 +524,28 @@ maybe_setup_valgrind () {\n \tfi\n }\n \n+# This is a separate function because some tests use\n+# \"return\" to end a test_expect_success block early\n+# (and we want to make sure we run any $test_eval_end_).\n+test_eval_inner_ () {\n+\teval \"$test_eval_start_ $*\"\n+}\n+\n test_eval_ () {\n-\t# This is a separate function because some tests use\n-\t# \"return\" to end a test_expect_success block early.\n-\teval </dev/null >&3 2>&4 \"$*\"\n+\t# We run this block with stderr redirected to avoid extra cruft\n+\t# during a \"-x\" trace. Once in \"set -x\" mode, we cannot prevent\n+\t# the shell from printing the \"set +x\" to turn it off (nor the saving\n+\t# of $? before that). But we can make sure that the output goes to\n+\t# /dev/null.\n+\t#\n+\t# The test itself is run with stderr put back to &4 (so either to\n+\t# /dev/null, or to the original stderr if --verbose was used).\n+\t{\n+\t\ttest_eval_inner_ \"$@\" </dev/null >&3 2>&4\n+\t\ttest_eval_ret_=$?\n+\t\t$test_eval_end_\n+\t} 2>/dev/null\n+\treturn $test_eval_ret_\n }\n \n test_run_ () {\n@@ -531,7 +556,8 @@ test_run_ () {\n \teval_ret=$?\n \tteardown_malloc_check\n \n-\tif test -z \"$immediate\" || test $eval_ret = 0 || test -n \"$expecting_failure\"\n+\tif test -z \"$immediate\" || test $eval_ret = 0 ||\n+\t   test -n \"$expecting_failure\" && test \"$test_cleanup\" != \":\"\n \tthen\n \t\tsetup_malloc_check\n \t\ttest_eval_ \"$test_cleanup\"\n-- \n2.1.2.596.g7379948\n"},{"id":"250469","messageId":"20141010062156.GA17481@peff.net","threadId":"37703","inReplyTo":"20141010061355.GC15277@peff.net","subject":"Re: [PATCH 3/3] test-lib.sh: support -x option for shell-tracing","fromName":"Jeff King","fromEmail":"peff@peff.net","sentAt":"2014-10-10T06:21:56Z","receivedAt":"2014-10-10T06:21:56Z","isPatch":true,"sender":{"key":"peff@peff.net","avatar":"https://avatars.githubusercontent.com/u/45925?v=4"},"body":"On Fri, Oct 10, 2014 at 02:13:55AM -0400, Jeff King wrote:\n\n> Having finally figured out how to drop the \"set +x\" from the output, I\n> have noticed that I kind of liked the \"test_eval_ret=$?\" part of the\n> trace (which is now gone, too), because it pretty explicitly tells you\n> that the last traced command failed. But now that it has been silenced,\n> there's no reason we couldn't add back in our own output to make it more\n> clear.\n\nLike:\n\ndiff --git a/t/test-lib.sh b/t/test-lib.sh\nindex a60ec75..81ceb23 100644\n--- a/t/test-lib.sh\n+++ b/t/test-lib.sh\n@@ -237,7 +237,11 @@ do\n \t\tshift ;;\n \t-x)\n \t\ttest_eval_start_='set -x'\n-\t\ttest_eval_end_='set +x'\n+\t\ttest_eval_end_='\n+\t\t\tset +x\n+\t\t\ttest \"$test_eval_ret_\" = 0 ||\n+\t\t\t  say_color error >&4 \"last command exited with \\$?=$?\"\n+\t\t'\n \t\tverbose=t\n \t\tshift ;;\n \t*)\n@@ -543,7 +547,7 @@ test_eval_ () {\n \t{\n \t\ttest_eval_inner_ \"$@\" </dev/null >&3 2>&4\n \t\ttest_eval_ret_=$?\n-\t\t$test_eval_end_\n+\t\teval \"$test_eval_end_\"\n \t} 2>/dev/null\n \treturn $test_eval_ret_\n }\n\nI think we can probably do away with this excessive use of eval, and\njust keep a boolean flag for \"is -x in effect\" and check it inside\ntest_eval_. Originally I was trying to keep the number of executed\ncommands down, because everything until the \"set +x\" ran (including\nchecks for an \"is -x in effect\" flag) was shown to the user. But since\nthat is no longer the case, we can be less stingy with the conditionals.\n\n-Peff\n"},{"id":"250470","messageId":"20141010062722.GB17481@peff.net","threadId":"37703","inReplyTo":"20141010061355.GC15277@peff.net","subject":"Re: [PATCH 3/3] test-lib.sh: support -x option for shell-tracing","fromName":"Jeff King","fromEmail":"peff@peff.net","sentAt":"2014-10-10T06:27:22Z","receivedAt":"2014-10-10T06:27:22Z","isPatch":true,"sender":{"key":"peff@peff.net","avatar":"https://avatars.githubusercontent.com/u/45925?v=4"},"body":"On Fri, Oct 10, 2014 at 02:13:55AM -0400, Jeff King wrote:\n\n> +\t-x)\n> +\t\ttest_eval_start_='set -x'\n> [...]\n> +\teval \"$test_eval_start_ $*\"\n> +}\n\nHmph. I had originally intended to make this \"set -x;\" with a semicolon,\nto keep it split from $*. But I forgot to, and much to my surprise, all\nof the tests still passed. I think that is because each of the tests\nis one of:\n\n  1. Long, in which case we split the commands into their own line,\n     like:\n\n        test_expect_success 'foo' '\n\t\tsome command\n\t'\n\n     and the leading newline serves as the separator.\n\nor\n\n  2. Short, like:\n\n       test_expect_success 'foo' 'bar'\n\n     in which case we did not run the test at all, but merely set $1 to\n     'bar', which of course succeeded. Whoops!\n\nStill, I'm surprised that nothing failed due to case 2.  I'll send a\nre-roll in a moment.\n\n-Peff\n"},{"id":"250472","messageId":"20141010064727.GC17481@peff.net","threadId":"37703","inReplyTo":"20141010062722.GB17481@peff.net","subject":"[PATCH v2 3/3] test-lib.sh: support -x option for shell-tracing","fromName":"Jeff King","fromEmail":"peff@peff.net","sentAt":"2014-10-10T06:47:27Z","receivedAt":"2014-10-10T06:47:27Z","isPatch":true,"sender":{"key":"peff@peff.net","avatar":"https://avatars.githubusercontent.com/u/45925?v=4"},"body":"On Fri, Oct 10, 2014 at 02:21:56AM -0400, Jeff King wrote:\n\n> diff --git a/t/test-lib.sh b/t/test-lib.sh\n> index a60ec75..81ceb23 100644\n> --- a/t/test-lib.sh\n> +++ b/t/test-lib.sh\n> @@ -237,7 +237,11 @@ do\n>  \t\tshift ;;\n>  \t-x)\n>  \t\ttest_eval_start_='set -x'\n> -\t\ttest_eval_end_='set +x'\n> +\t\ttest_eval_end_='\n> +\t\t\tset +x\n> +\t\t\ttest \"$test_eval_ret_\" = 0 ||\n> +\t\t\t  say_color error >&4 \"last command exited with \\$?=$?\"\n\nThat should be \\$?=$test_eval_ret_, of course. The patch below fixes it.\n\n> I think we can probably do away with this excessive use of eval, and\n> just keep a boolean flag for \"is -x in effect\" and check it inside\n> test_eval_. Originally I was trying to keep the number of executed\n> commands down, because everything until the \"set +x\" ran (including\n> checks for an \"is -x in effect\" flag) was shown to the user. But since\n> that is no longer the case, we can be less stingy with the conditionals.\n\nThe patch below does so. The result is much cleaner.\n\n> Hmph. I had originally intended to make this \"set -x;\" with a semicolon,\n> to keep it split from $*. But I forgot to, and much to my surprise, all\n> of the tests still passed.\n\nAnd by \"all\" I mean \"all of the handful that I ran with -x\". Of course\nthe bug does not show up when \"-x\" is not in use, which it was not when\nI ran \"make test\". *forehead palm*\n\nTrying to run the whole test suite with \"-x\" does fail. Some tests\ninvoke shell functions and redirect their stderr. The \"set -x\" will\npollute that output. There's not much we can do; it's sort of inherent\nin \"set -x\" (and it only seems to affect about 25 of the scripts, so I\nthink it's still a useful tool to have). I've added a warning to the\nREADME.\n\nRerolled patch is below. Sorry for all the emails. I'll stop looking at\nit now to give you guys a chance to find any remaining mistakes. ;)\n\n-- >8 --\nSubject: test-lib.sh: support -x option for shell-tracing\n\nUsually running a test under \"-v\" makes it clear which\ncommand is failing. However, sometimes it can be useful to\nalso see a complete trace of the shell commands being run in\nthe test. You can do so without any support from the test\nsuite by running \"sh -x tXXXX-foo.sh\". However, this\nproduces quite a large bit of output, as we see a trace of\nthe entire test suite.\n\nThis patch instead introduces a \"-x\" option to the test\nscripts (i.e., \"./tXXXX-foo.sh -x\"). When enabled, this\nturns on \"set -x\" only for the tests themselves. This can\nstill be a bit verbose, but should keep things to a more\nmanageable level. You can even use \"--verbose-only\" to see\nthe trace only for a specific test.\n\nThe implementation is a little invasive. We turn on the \"set\n-x\" inside the \"eval\" of the test code. This lets the eval\nitself avoid being reported in the trace (which would be\nlong, and redundant with the verbose listing we already\nshowed). And then after the eval runs, we do some trickery\nwith stderr to avoid showing the \"set +x\" to the user.\n\nWe also show traces for test_cleanup functions (since they\ncan impact the test outcome, too). However, we do avoid\nrunning the noop \":\" cleanup (the default if the test does\nnot use test_cleanup at all), as it creates unnecessary\nnoise in the \"set -x\" output.\n\nSigned-off-by: Jeff King <peff@peff.net>\n---\n t/README      |  6 ++++++\n t/test-lib.sh | 42 ++++++++++++++++++++++++++++++++++++++----\n 2 files changed, 44 insertions(+), 4 deletions(-)\n\ndiff --git a/t/README b/t/README\nindex 52c77ae..9952261 100644\n--- a/t/README\n+++ b/t/README\n@@ -82,6 +82,12 @@ appropriately before running \"make\".\n \tnumbers matching <pattern>.  The number matched against is\n \tsimply the running count of the test within the file.\n \n+-x::\n+\tTurn on shell tracing (i.e., `set -x`) during the tests\n+\tthemselves. Implies `--verbose`. Note that this can cause\n+\tfailures in some tests which redirect and test the\n+\toutput of shell functions. Use with caution.\n+\n -d::\n --debug::\n \tThis may help the person who is developing a new test.\ndiff --git a/t/test-lib.sh b/t/test-lib.sh\nindex 82095e3..4dab575 100644\n--- a/t/test-lib.sh\n+++ b/t/test-lib.sh\n@@ -233,6 +233,10 @@ do\n \t--root=*)\n \t\troot=$(expr \"z$1\" : 'z[^=]*=\\(.*\\)')\n \t\tshift ;;\n+\t-x)\n+\t\ttrace=t\n+\t\tverbose=t\n+\t\tshift ;;\n \t*)\n \t\techo \"error: unknown test option '$1'\" >&2; exit 1 ;;\n \tesac\n@@ -517,10 +521,39 @@ maybe_setup_valgrind () {\n \tfi\n }\n \n+# This is a separate function because some tests use\n+# \"return\" to end a test_expect_success block early\n+# (and we want to make sure we run any cleanup like\n+# \"set +x\").\n+test_eval_inner_ () {\n+\teval \"\n+\t\ttest \\\"$trace\\\" = t && set -x\n+\t\t$*\n+\t\"\n+}\n+\n test_eval_ () {\n-\t# This is a separate function because some tests use\n-\t# \"return\" to end a test_expect_success block early.\n-\teval </dev/null >&3 2>&4 \"$*\"\n+\t# We run this block with stderr redirected to avoid extra cruft\n+\t# during a \"-x\" trace. Once in \"set -x\" mode, we cannot prevent\n+\t# the shell from printing the \"set +x\" to turn it off (nor the saving\n+\t# of $? before that). But we can make sure that the output goes to\n+\t# /dev/null.\n+\t#\n+\t# The test itself is run with stderr put back to &4 (so either to\n+\t# /dev/null, or to the original stderr if --verbose was used).\n+\t{\n+\t\ttest_eval_inner_ \"$@\" </dev/null >&3 2>&4\n+\t\ttest_eval_ret_=$?\n+\t\tif test \"$trace\" = t\n+\t\tthen\n+\t\t\tset +x\n+\t\t\tif test \"$test_eval_ret_\" != 0\n+\t\t\tthen\n+\t\t\t\tsay_color error >&4 \"error: last command exited with \\$?=$test_eval_ret_\"\n+\t\t\tfi\n+\t\tfi\n+\t} 2>/dev/null\n+\treturn $test_eval_ret_\n }\n \n test_run_ () {\n@@ -531,7 +564,8 @@ test_run_ () {\n \teval_ret=$?\n \tteardown_malloc_check\n \n-\tif test -z \"$immediate\" || test $eval_ret = 0 || test -n \"$expecting_failure\"\n+\tif test -z \"$immediate\" || test $eval_ret = 0 ||\n+\t   test -n \"$expecting_failure\" && test \"$test_cleanup\" != \":\"\n \tthen\n \t\tsetup_malloc_check\n \t\ttest_eval_ \"$test_cleanup\"\n-- \n2.1.2.596.g7379948\n"},{"id":"250541","messageId":"20141013161022.GA20520@google.com","threadId":"37703","inReplyTo":"20141010061114.GB15277@peff.net","subject":"Re: [PATCH 2/3] t5304: use helper to report failure of \"test foo = bar\"","fromName":"Jonathan Nieder","fromEmail":"jrnieder@gmail.com","sentAt":"2014-10-13T16:10:22Z","receivedAt":"2014-10-13T16:10:22Z","isPatch":true,"sender":{"key":"jrnieder@gmail.com","avatar":"https://avatars.githubusercontent.com/u/281595?v=4"},"body":"Jeff King wrote:\n\n> For small outputs, we sometimes use:\n>\n>   test \"$(some_cmd)\" = \"something we expect\"\n>\n> instead of a full test_cmp. The downside of this is that\n> when it fails, there is no output at all from the script.\n\nThere's another downside to that construct: it loses the exit\nstatus from some_cmd.\n\n[...]\n> --- a/t/t5304-prune.sh\n> +++ b/t/t5304-prune.sh\n> @@ -13,7 +13,7 @@ add_blob() {\n>  \tbefore=$(git count-objects | sed \"s/ .*//\") &&\n>  \tBLOB=$(echo aleph_0 | git hash-object -w --stdin) &&\n>  \tBLOB_FILE=.git/objects/$(echo $BLOB | sed \"s/^../&\\//\") &&\n> -\ttest $((1 + $before)) = $(git count-objects | sed \"s/ .*//\") &&\n> +\tverbose test $((1 + $before)) = $(git count-objects | sed \"s/ .*//\") &&\n\nSo ideally this would be something like:\n\n\tgit count-objects >output &&\n\tverbose test \"$((1 + $before))\" = \"$(sed \"s/ .*//\" output)\" &&\n\n[...]\n> @@ -45,11 +45,11 @@ test_expect_success 'prune --expire' '\n>  \n>  \tadd_blob &&\n>  \tgit prune --expire=1.hour.ago &&\n> -\ttest $((1 + $before)) = $(git count-objects | sed \"s/ .*//\") &&\n> +\tverbose test $((1 + $before)) = $(git count-objects | sed \"s/ .*//\") &&\n\nand likewise elsewhere in the file.\n\nAlternatively, maybe there could be a helper in the same spirit as\ntest_cmp_rev?\n\n\ttest_object_count () {\n\t\tgit count-objects >output &&\n\t\tsed \"s/ .*//\" output >count &&\n\t\tprintf \"%s\\n\" \"$1\" >expect &&\n\t\ttest_cmp expect count\n\t}\n\nMy two cents,\nJonathan\n"},{"id":"250560","messageId":"xmqqd29v4yl1.fsf@gitster.dls.corp.google.com","threadId":"37703","inReplyTo":"20141010060636.GA15057@peff.net","subject":"Re: [PATCH 0/3] \"-x\" tracing option for tests","fromName":"Junio C Hamano","fromEmail":"gitster@pobox.com","sentAt":"2014-10-13T18:24:42Z","receivedAt":"2014-10-13T18:24:42Z","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> These patches are pulled out of the prune-mtime series I posted\n> earlier[1]. The discussion veered off and there's no reason that the two\n> topics need to be part of the same series.\n\nThese look all sensible.\n\nIs your plan to reroll the prune-mtime stuff on top of these?  The\nadditional safety those patches would give us is valuable and they\nare pretty straight-forward---I was hoping to have them in the 2.2\nrelease.\n\nThanks.\n"},{"id":"250562","messageId":"xmqq8ukj4xpn.fsf@gitster.dls.corp.google.com","threadId":"37703","inReplyTo":"20141010064727.GC17481@peff.net","subject":"Re: [PATCH v2 3/3] test-lib.sh: support -x option for shell-tracing","fromName":"Junio C Hamano","fromEmail":"gitster@pobox.com","sentAt":"2014-10-13T18:43:32Z","receivedAt":"2014-10-13T18:43:32Z","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>> Hmph. I had originally intended to make this \"set -x;\" with a semicolon,\n>> to keep it split from $*. But I forgot to, and much to my surprise, all\n>> of the tests still passed.\n\nYup, I was wondering why you posted a version without the semicolon,\nwhich looked obviously bogus, as I've never seen you post an\nuntested thing without marking as such.\n\n> +\t# The test itself is run with stderr put back to &4 (so either to\n> +\t# /dev/null, or to the original stderr if --verbose was used).\n> +\t{\n> +\t\ttest_eval_inner_ \"$@\" </dev/null >&3 2>&4\n> +\t\ttest_eval_ret_=$?\n> +\t\tif test \"$trace\" = t\n> +\t\tthen\n> +\t\t\tset +x\n> +\t\t\tif test \"$test_eval_ret_\" != 0\n> +\t\t\tthen\n> +\t\t\t\tsay_color error >&4 \"error: last command exited with \\$?=$test_eval_ret_\"\n> +\t\t\tfi\n> +\t\tfi\n> +\t} 2>/dev/null\n\nHmph, that is a clever way to squelch output from set+x (and\neverything that runs after the eval returns) I never thought of.\n\nNice.\n"},{"id":"250576","messageId":"20141013210729.GA15969@peff.net","threadId":"37703","inReplyTo":"xmqqd29v4yl1.fsf@gitster.dls.corp.google.com","subject":"Re: [PATCH 0/3] \"-x\" tracing option for tests","fromName":"Jeff King","fromEmail":"peff@peff.net","sentAt":"2014-10-13T21:07:29Z","receivedAt":"2014-10-13T21:07:29Z","isPatch":true,"sender":{"key":"peff@peff.net","avatar":"https://avatars.githubusercontent.com/u/45925?v=4"},"body":"On Mon, Oct 13, 2014 at 11:24:42AM -0700, Junio C Hamano wrote:\n\n> Jeff King <peff@peff.net> writes:\n> \n> > These patches are pulled out of the prune-mtime series I posted\n> > earlier[1]. The discussion veered off and there's no reason that the two\n> > topics need to be part of the same series.\n> \n> These look all sensible.\n> \n> Is your plan to reroll the prune-mtime stuff on top of these?  The\n> additional safety those patches would give us is valuable and they\n> are pretty straight-forward---I was hoping to have them in the 2.2\n> release.\n\nYes, I've delayed while thinking about the issues that Michael raised.\nThere are basically two paths I see:\n\n  1. These do not solve all problems/races, but are a solid base and\n     sensible path forward for further changes which we can worry about\n     later.\n\n  2. There is a better way to provide prune safety, and these patches\n     will get in the way of doing that.\n\nI wanted to make sure we are on path (1) and not path (2). :)\n\nI'll try to send out a re-roll tonight.\n\n-Peff\n"},{"id":"250577","messageId":"20141013211524.GB15969@peff.net","threadId":"37703","inReplyTo":"20141013161022.GA20520@google.com","subject":"Re: [PATCH 2/3] t5304: use helper to report failure of \"test foo = bar\"","fromName":"Jeff King","fromEmail":"peff@peff.net","sentAt":"2014-10-13T21:15:25Z","receivedAt":"2014-10-13T21:15:25Z","isPatch":true,"sender":{"key":"peff@peff.net","avatar":"https://avatars.githubusercontent.com/u/45925?v=4"},"body":"On Mon, Oct 13, 2014 at 09:10:22AM -0700, Jonathan Nieder wrote:\n\n> Jeff King wrote:\n> \n> > For small outputs, we sometimes use:\n> >\n> >   test \"$(some_cmd)\" = \"something we expect\"\n> >\n> > instead of a full test_cmp. The downside of this is that\n> > when it fails, there is no output at all from the script.\n> \n> There's another downside to that construct: it loses the exit\n> status from some_cmd.\n\nYes, although I think in many cases it's not a big deal. For example,\nhere we lose the exit code of count-objects, but it also is very\nunlikely to fail _and_ produce our expected output.\n\n> Alternatively, maybe there could be a helper in the same spirit as\n> test_cmp_rev?\n> \n> \ttest_object_count () {\n> \t\tgit count-objects >output &&\n> \t\tsed \"s/ .*//\" output >count &&\n> \t\tprintf \"%s\\n\" \"$1\" >expect &&\n> \t\ttest_cmp expect count\n> \t}\n\nOne of my goals was to provide a more generic helper so that we don't\nhave to make little helpers like this for every command. So I'd much\nrather something like:\n\n  test_output () {\n\tprintf \"%s\\n\" \"$1\" >expect &&\n\tshift &&\n\t\"$@\" >output &&\n\ttest_cmp expect output\n  }\n\nThe \"\\n\" handling there feels a little hacky, but is probably OK in\npractice (the few commands that really do generate an output without a\nnewline can use test_cmp manually). It should probably also \"rm\" the\nfiles on success to avoid polluting the working tree.\n\nIt also doesn't help cases that want to do \"test $foo -lt 3\" or other\nnon-equality checks. But those are probably the minority.\n\nI dunno. I am OK with what I posted, but if we feel strongly about\ntesting the exit code, I can re-roll as test_output as above.\n\n-Peff\n"},{"id":"250579","messageId":"20141013213132.GA32245@google.com","threadId":"37703","inReplyTo":"20141013211524.GB15969@peff.net","subject":"Re: [PATCH 2/3] t5304: use helper to report failure of \"test foo = bar\"","fromName":"Jonathan Nieder","fromEmail":"jrnieder@gmail.com","sentAt":"2014-10-13T21:31:32Z","receivedAt":"2014-10-13T21:31:32Z","isPatch":true,"sender":{"key":"jrnieder@gmail.com","avatar":"https://avatars.githubusercontent.com/u/281595?v=4"},"body":"Jeff King wrote:\n> On Mon, Oct 13, 2014 at 09:10:22AM -0700, Jonathan Nieder wrote:\n\n>> There's another downside to that construct: it loses the exit\n>> status from some_cmd.\n>\n> Yes, although I think in many cases it's not a big deal. For example,\n> here we lose the exit code of count-objects, but it also is very\n> unlikely to fail _and_ produce our expected output.\n\nIt could segfault after producing the good output, but sure,\ncount-objects code doesn't change very often.\n\n[...]\n> One of my goals was to provide a more generic helper so that we don't\n> have to make little helpers like this for every command. So I'd much\n> rather something like:\n>\n>   test_output () {\n> \tprintf \"%s\\n\" \"$1\" >expect &&\n> \tshift &&\n> \t\"$@\" >output &&\n> \ttest_cmp expect output\n>   }\n\nI agree with the principle in general.\n\nUnfortunately that wouldn't help here --- the \"$@\" is a command with a\npipe to sed in it and we still lose the exit status from\ncount-objects.\n\nHoping that clarifies,\nJonathan\n"},{"id":"250580","messageId":"CAPc5daX7UBvxCw60VUW4rUkKYbD8Do+=Nczq=z=ykoykZA+ywQ@mail.gmail.com","threadId":"37703","inReplyTo":"20141013213132.GA32245@google.com","subject":"Re: [PATCH 2/3] t5304: use helper to report failure of \"test foo = bar\"","fromName":"Junio C Hamano","fromEmail":"gitster@pobox.com","sentAt":"2014-10-13T21:33:48Z","receivedAt":"2014-10-13T21:33:48Z","isPatch":true,"sender":{"key":"gitster@pobox.com","avatar":"https://avatars.githubusercontent.com/u/54884?v=4"},"body":"On Mon, Oct 13, 2014 at 2:31 PM, Jonathan Nieder <jrnieder@gmail.com> wrote:\n> Jeff King wrote:\n>> On Mon, Oct 13, 2014 at 09:10:22AM -0700, Jonathan Nieder wrote:\n>\n>>> There's another downside to that construct: it loses the exit\n>>> status from some_cmd.\n>>\n>> Yes, although I think in many cases it's not a big deal. For example,\n>> here we lose the exit code of count-objects, but it also is very\n>> unlikely to fail _and_ produce our expected output.\n>\n> It could segfault after producing the good output, but sure,\n> count-objects code doesn't change very often.\n\n\"Doesn't change very often\" is not the issue. Here we are not testing\nif it can count correctly without crashing, which *is* the real reason\nwhy it is perfectly fine to use $(git count-objects | sed ...) pattern here.\n\nThere of course should be a test for count-objects to make sure it\ncounts correctly without crashing.\n"},{"id":"250581","messageId":"20141013213633.GA16732@peff.net","threadId":"37703","inReplyTo":"20141013213132.GA32245@google.com","subject":"Re: [PATCH 2/3] t5304: use helper to report failure of \"test foo = bar\"","fromName":"Jeff King","fromEmail":"peff@peff.net","sentAt":"2014-10-13T21:36:33Z","receivedAt":"2014-10-13T21:36:33Z","isPatch":true,"sender":{"key":"peff@peff.net","avatar":"https://avatars.githubusercontent.com/u/45925?v=4"},"body":"On Mon, Oct 13, 2014 at 02:31:32PM -0700, Jonathan Nieder wrote:\n\n> > One of my goals was to provide a more generic helper so that we don't\n> > have to make little helpers like this for every command. So I'd much\n> > rather something like:\n> >\n> >   test_output () {\n> > \tprintf \"%s\\n\" \"$1\" >expect &&\n> > \tshift &&\n> > \t\"$@\" >output &&\n> > \ttest_cmp expect output\n> >   }\n> \n> I agree with the principle in general.\n> \n> Unfortunately that wouldn't help here --- the \"$@\" is a command with a\n> pipe to sed in it and we still lose the exit status from\n> count-objects.\n\nThanks, I missed that subtlety from what you posted earlier. That's\nanother good reason that something like test_output is not really\nsufficient (you could eval() a snippet of shell, but then we have not\nreally improved on the \"verbose test $a = $b\" version, since as you note\nwe are still missing the exit code).\n\n-Peff\n"},{"id":"250582","messageId":"20141013213808.GB32245@google.com","threadId":"37703","inReplyTo":"CAPc5daX7UBvxCw60VUW4rUkKYbD8Do+=Nczq=z=ykoykZA+ywQ@mail.gmail.com","subject":"Re: [PATCH 2/3] t5304: use helper to report failure of \"test foo = bar\"","fromName":"Jonathan Nieder","fromEmail":"jrnieder@gmail.com","sentAt":"2014-10-13T21:38:08Z","receivedAt":"2014-10-13T21:38:08Z","isPatch":true,"sender":{"key":"jrnieder@gmail.com","avatar":"https://avatars.githubusercontent.com/u/281595?v=4"},"body":"Junio C Hamano wrote:\n> On Mon, Oct 13, 2014 at 2:31 PM, Jonathan Nieder <jrnieder@gmail.com> wrote:\n\n>> It could segfault after producing the good output, but sure,\n>> count-objects code doesn't change very often.\n>\n> \"Doesn't change very often\" is not the issue. Here we are not testing\n> if it can count correctly without crashing, which *is* the real reason\n> why it is perfectly fine to use $(git count-objects | sed ...) pattern here.\n>\n> There of course should be a test for count-objects to make sure it\n> counts correctly without crashing.\n\nThat also makes sense, but it is a pretty big change from the general\nstrategy used in git tests today.\n\nCurrently they use &&-chaining to check the status from git commands\nused along the way.  That way, unrelated bugs in git commands that are\nonly used incidentally get caught, as long as they cause the command\nto crash.  This has helped me in the past to find weird bugs early\nwhen they cause some particular command to crash on some platforms.\nSometimes they are races that show up on more popular platforms later.\n\nJonathan\n"},{"id":"250584","messageId":"xmqqppdv1vnh.fsf@gitster.dls.corp.google.com","threadId":"37703","inReplyTo":"20141013213808.GB32245@google.com","subject":"Re: [PATCH 2/3] t5304: use helper to report failure of \"test foo = bar\"","fromName":"Junio C Hamano","fromEmail":"gitster@pobox.com","sentAt":"2014-10-13T21:56:18Z","receivedAt":"2014-10-13T21:56:18Z","isPatch":true,"sender":{"key":"gitster@pobox.com","avatar":"https://avatars.githubusercontent.com/u/54884?v=4"},"body":"Jonathan Nieder <jrnieder@gmail.com> writes:\n\n> Junio C Hamano wrote:\n>> On Mon, Oct 13, 2014 at 2:31 PM, Jonathan Nieder <jrnieder@gmail.com> wrote:\n>\n>>> It could segfault after producing the good output, but sure,\n>>> count-objects code doesn't change very often.\n>>\n>> \"Doesn't change very often\" is not the issue. Here we are not testing\n>> if it can count correctly without crashing, which *is* the real reason\n>> why it is perfectly fine to use $(git count-objects | sed ...) pattern here.\n>>\n>> There of course should be a test for count-objects to make sure it\n>> counts correctly without crashing.\n>\n> That also makes sense, but it is a pretty big change from the general\n> strategy used in git tests today.\n\nI would have to say that you are mistaken in reading what the\n\"strategy used today\" is.  There is a subtle trade-off involved.\n\nWhen we test, say, \"git add a b\", we may want to test these things:\n\n    - \"git add\" when given addable paths a and b finishes without\n      crashing;\n\n    - \"git add\" will leave these paths in the index as expected.\n\nAnd we write\n\n\tgit add a b &&\n\ttest_write_lines a b >expect &&\n        git ls-files a b >actual &&\n        test_cmp expect actual\n\nNOT because we expect \"printf\" (which underlies test_write_lines) or\n\"git ls-files\" could somehow misbehave and dump core, but primarily\nbecause compared to an alternative, e.g.\n\n\tgit add a b || return 1\n        test_write_lines a b >expect\n        git ls-files a b >actual\n        test_cmp expect actual\n\nit is far cleaner and easier to read with a rhythm.  It is just an\nadded bonus that we may catch errors due to filesystem quota when\nwriting to \"expect\" or ls-files crashing.  If the alternative had\nenough advantage over the established pattern (and here is where the\ntrade off comes in---you need a certain taste to judge the\nadvantage), it is perfectly fine to trade the exit value off and\nfavor the advantage the alternative offers (e.g. a test that is\neasier to read).\n\nBetween these two, it is very sensible to take A. over B.\n\n    A.\n\tgit create-garbage &&\n\ttest $(git count-objects | sed ... | wc -l) = 0\n\n    B.\n\tgit create-garbage &&\n\ttest_when_finished \"rm -f tmp\" &&\n        git count-objects >tmp &&\n        test $(sed ... tmp | wc -l) = 0\n\nIt will shift the trade-off if the more verbose alternative gets\nwrapped into a helper that is well constructed, though, because\nreadability advantage of A over B melts away when we do so.\n"},{"id":"250586","messageId":"xmqqh9z71uf9.fsf@gitster.dls.corp.google.com","threadId":"37703","inReplyTo":"20141010064727.GC17481@peff.net","subject":"Re: [PATCH v2 3/3] test-lib.sh: support -x option for shell-tracing","fromName":"Junio C Hamano","fromEmail":"gitster@pobox.com","sentAt":"2014-10-13T22:22:50Z","receivedAt":"2014-10-13T22:22:50Z","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> On Fri, Oct 10, 2014 at 02:21:56AM -0400, Jeff King wrote:\n>\n>> diff --git a/t/test-lib.sh b/t/test-lib.sh\n>> index a60ec75..81ceb23 100644\n>> --- a/t/test-lib.sh\n>> +++ b/t/test-lib.sh\n>> @@ -237,7 +237,11 @@ do\n>>  \t\tshift ;;\n>>  \t-x)\n>>  \t\ttest_eval_start_='set -x'\n>> -\t\ttest_eval_end_='set +x'\n>> +\t\ttest_eval_end_='\n>> +\t\t\tset +x\n>> +\t\t\ttest \"$test_eval_ret_\" = 0 ||\n>> +\t\t\t  say_color error >&4 \"last command exited with \\$?=$?\"\n>\n> That should be \\$?=$test_eval_ret_, of course. The patch below fixes it.\n>\n> Rerolled patch is below. Sorry for all the emails. I'll stop looking at\n> it now to give you guys a chance to find any remaining mistakes. ;)\n\nDoes 1308 pass with this patch for you (running it without \"-x\")?\n\nThe original that expects a hardcoded line number (not relative to\nthe original or something) is a bad taste, and also the test setup\nprocedure is broken (see below for a fix of that breakage, which\ndoes not fix the breakage this patch seems to bring in anyway).\n\nBut still it is disturbing to see that there is a blank line\ndifference with and without this change in the file created by the\ntest (i.e. the client of the code this patch touches).\n\n t/t1308-config-set.sh | 2 +-\n 1 file changed, 1 insertion(+), 1 deletion(-)\n\ndiff --git a/t/t1308-config-set.sh b/t/t1308-config-set.sh\nindex ea0bce2..462bb64 100755\n--- a/t/t1308-config-set.sh\n+++ b/t/t1308-config-set.sh\n@@ -23,7 +23,7 @@ check_config () {\n }\n \n test_expect_success 'setup default config' '\n-\tcat >.git/config <<\\EOF\n+\tcat >.git/config <<-\\EOF\n \t[case]\n \t\tpenguin = very blue\n \t\tMovie = BadPhysics\n"},{"id":"250587","messageId":"xmqqd29v1u0a.fsf@gitster.dls.corp.google.com","threadId":"37703","inReplyTo":"xmqqh9z71uf9.fsf@gitster.dls.corp.google.com","subject":"Re: [PATCH v2 3/3] test-lib.sh: support -x option for shell-tracing","fromName":"Junio C Hamano","fromEmail":"gitster@pobox.com","sentAt":"2014-10-13T22:31:49Z","receivedAt":"2014-10-13T22:31:49Z","isPatch":true,"sender":{"key":"gitster@pobox.com","avatar":"https://avatars.githubusercontent.com/u/54884?v=4"},"body":"Junio C Hamano <gitster@pobox.com> writes:\n\n> Does 1308 pass with this patch for you (running it without \"-x\")?\n>\n> The original that expects a hardcoded line number (not relative to\n> the original or something) is a bad taste, and also the test setup\n> procedure is broken (see below for a fix of that breakage, which\n> does not fix the breakage this patch seems to bring in anyway).\n>\n> But still it is disturbing to see that there is a blank line\n> difference with and without this change in the file created by the\n> test (i.e. the client of the code this patch touches).\n\nThis is even more disturbing.  With this fix (which is correct as\nfar as I can tell) queued on top of ta/config-set, the shell-tracing\npatch does not fail any more.\n\nI suspect that the broken test in the original ended the .git/config\nfile with an incomplete line or something, and with the attached fix\nwe no longer do so and that is why shell-tracing patch no longer\nbreaks it, it seems.  So if there is a test that does want to create\na file that ends with an incomplete line, we may see the real\nbreakage again with the shell-tracing patch in.\n\n\n\n-- >8 --\nSubject: [PATCH] t1308: fix broken here document in test script\n\nSigned-off-by: Junio C Hamano <gitster@pobox.com>\n---\n t/t1308-config-set.sh | 4 ++--\n 1 file changed, 2 insertions(+), 2 deletions(-)\n\ndiff --git a/t/t1308-config-set.sh b/t/t1308-config-set.sh\nindex 7fdf840..243d612 100755\n--- a/t/t1308-config-set.sh\n+++ b/t/t1308-config-set.sh\n@@ -23,7 +23,7 @@ check_config () {\n }\n \n test_expect_success 'setup default config' '\n-\tcat >.git/config <<\\EOF\n+\tcat >.git/config <<-\\EOF\n \t[case]\n \t\tpenguin = very blue\n \t\tMovie = BadPhysics\n@@ -185,7 +185,7 @@ test_expect_success 'proper error on error in default config files' '\n \tcp .git/config .git/config.old &&\n \ttest_when_finished \"mv .git/config.old .git/config\" &&\n \techo \"[\" >>.git/config &&\n-\techo \"fatal: bad config file line 35 in .git/config\" >expect &&\n+\techo \"fatal: bad config file line 34 in .git/config\" >expect &&\n \ttest_expect_code 128 test-config get_value foo.bar 2>actual &&\n \ttest_cmp expect actual\n '\n-- \n2.1.2-468-g1a77c5b\n"},{"id":"250588","messageId":"20141013223303.GA17045@peff.net","threadId":"37703","inReplyTo":"xmqqh9z71uf9.fsf@gitster.dls.corp.google.com","subject":"Re: [PATCH v2 3/3] test-lib.sh: support -x option for shell-tracing","fromName":"Jeff King","fromEmail":"peff@peff.net","sentAt":"2014-10-13T22:33:03Z","receivedAt":"2014-10-13T22:33:03Z","isPatch":true,"sender":{"key":"peff@peff.net","avatar":"https://avatars.githubusercontent.com/u/45925?v=4"},"body":"On Mon, Oct 13, 2014 at 03:22:50PM -0700, Junio C Hamano wrote:\n\n> > Rerolled patch is below. Sorry for all the emails. I'll stop looking at\n> > it now to give you guys a chance to find any remaining mistakes. ;)\n> \n> Does 1308 pass with this patch for you (running it without \"-x\")?\n\nHmph. It does not. I know that \"make test\" passed with an earlier\niteration, but I must have gotten so wrapped up in testing \"make\nGIT_TEST_OPTS=-x test\" that I never ran a vanilla \"make test\" on\nwhat I finally posted. Sorry.\n\n> The original that expects a hardcoded line number (not relative to\n> the original or something) is a bad taste, and also the test setup\n> procedure is broken (see below for a fix of that breakage, which\n> does not fix the breakage this patch seems to bring in anyway).\n\nYeah, I agree, and your patch below looks reasonable.\n\n> But still it is disturbing to see that there is a blank line\n> difference with and without this change in the file created by the\n> test (i.e. the client of the code this patch touches).\n\nThis fixes it:\n\ndiff --git a/t/test-lib.sh b/t/test-lib.sh\nindex 4dab575..059bb25 100644\n--- a/t/test-lib.sh\n+++ b/t/test-lib.sh\n@@ -528,8 +528,7 @@ maybe_setup_valgrind () {\n test_eval_inner_ () {\n \teval \"\n \t\ttest \\\"$trace\\\" = t && set -x\n-\t\t$*\n-\t\"\n+\t\t$*\"\n }\n \n test_eval_ () {\n\n\nMy patch definitely expands the snippet with an extra trailing newline.\nBut what I really don't understand is why that would impact the\n_contents_ of the config file.\n\nI'll dig further, but I'm about to leave the computer for dinner for a\nfew hours, so please don't hold your breath. :)\n\n-Peff\n"},{"id":"250589","messageId":"xmqq8ukj1toi.fsf@gitster.dls.corp.google.com","threadId":"37703","inReplyTo":"20141013223303.GA17045@peff.net","subject":"Re: [PATCH v2 3/3] test-lib.sh: support -x option for shell-tracing","fromName":"Junio C Hamano","fromEmail":"gitster@pobox.com","sentAt":"2014-10-13T22:38:53Z","receivedAt":"2014-10-13T22:38:53Z","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> This fixes it:\n>\n> diff --git a/t/test-lib.sh b/t/test-lib.sh\n> index 4dab575..059bb25 100644\n> --- a/t/test-lib.sh\n> +++ b/t/test-lib.sh\n> @@ -528,8 +528,7 @@ maybe_setup_valgrind () {\n>  test_eval_inner_ () {\n>  \teval \"\n>  \t\ttest \\\"$trace\\\" = t && set -x\n> -\t\t$*\n> -\t\"\n> +\t\t$*\"\n>  }\n>  \n>  test_eval_ () {\n>\n>\n> My patch definitely expands the snippet with an extra trailing newline.\n> But what I really don't understand is why that would impact the\n> _contents_ of the config file.\n\nAhh, OK.  The inside of eval begins with\n\n\tcat >.git/config <<\\EOF\n        ...\n\nand ends with \"<HT>EOF\", which is _ignored_ because it is not \"EOF\"\nalone on a line, so the shell takes everything, i.e. including the\nadditional LF your dq.  No wonder we got one extra line.\n\nAnd with that additional LF fixed, even if we do not fix t1308, it\nshould work (with some definition of \"work\") as before.\n\nThanks, that clears it up.\n"},{"id":"250590","messageId":"20141013224342.GA22290@peff.net","threadId":"37703","inReplyTo":"20141013223303.GA17045@peff.net","subject":"Re: [PATCH v2 3/3] test-lib.sh: support -x option for shell-tracing","fromName":"Jeff King","fromEmail":"peff@peff.net","sentAt":"2014-10-13T22:43:43Z","receivedAt":"2014-10-13T22:43:43Z","isPatch":true,"sender":{"key":"peff@peff.net","avatar":"https://avatars.githubusercontent.com/u/45925?v=4"},"body":"On Mon, Oct 13, 2014 at 06:33:03PM -0400, Jeff King wrote:\n\n> > But still it is disturbing to see that there is a blank line\n> > difference with and without this change in the file created by the\n> > test (i.e. the client of the code this patch touches).\n> \n> This fixes it:\n> \n> diff --git a/t/test-lib.sh b/t/test-lib.sh\n> index 4dab575..059bb25 100644\n> --- a/t/test-lib.sh\n> +++ b/t/test-lib.sh\n> @@ -528,8 +528,7 @@ maybe_setup_valgrind () {\n>  test_eval_inner_ () {\n>  \teval \"\n>  \t\ttest \\\"$trace\\\" = t && set -x\n> -\t\t$*\n> -\t\"\n> +\t\t$*\"\n>  }\n>  \n>  test_eval_ () {\n> \n> \n> My patch definitely expands the snippet with an extra trailing newline.\n> But what I really don't understand is why that would impact the\n> _contents_ of the config file.\n> \n> I'll dig further, but I'm about to leave the computer for dinner for a\n> few hours, so please don't hold your breath. :)\n\nOK, I lied. I couldn't resist spending 5 more minutes on it.\n\nIf you instrument t1308 on master to look at the contents of .git/config\ndirectly after the setup step, you'll see that the file ends with (tabs\nmarked as ^I):\n\n  [...]\n  ^I^Ihorns\n  ^IEOF\n\nWhich makes sense. We forgot the tab-eating \"<<-\" in the here-doc, so\nthe tab-indented EOF was not counted as the end of the input. So this\ntest is bogus and broken, and the breakage introduced by my patch is\nonly triggered because of that (which isn't to say we shouldn't\nnecessarily adjust my patch, but we definitely should fix this test).\n\nWhat really surprises me is that the shell is fine with a here-doc\nending inside an eval. Bash at least warns:\n\n  $ bash -c \"eval 'cat <<EOF\n    content'\"\n  bash: line 2: warning: here-document at line 1 delimited by end-of-file (wanted `EOF')\n      content\n\nbut dash silently accepts it:\n  $ dash -c \"eval 'cat <<EOF\n    content'\"\n      content\n\nMaybe this is something that every shell does, but it certainly seems\nlike something we should not be relying on (and it was definitely not\nsomething the test meant to rely on, as evidenced by the bogus EOF\nmarker it included).\n\n-Peff\n"},{"id":"250591","messageId":"xmqq4mv71s0c.fsf@gitster.dls.corp.google.com","threadId":"37703","inReplyTo":"20141013224342.GA22290@peff.net","subject":"Re: [PATCH v2 3/3] test-lib.sh: support -x option for shell-tracing","fromName":"Junio C Hamano","fromEmail":"gitster@pobox.com","sentAt":"2014-10-13T23:14:59Z","receivedAt":"2014-10-13T23:14:59Z","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> OK, I lied. I couldn't resist spending 5 more minutes on it.\n>\n> If you instrument t1308 on master to look at the contents of .git/config\n> directly after the setup step, you'll see that the file ends with (tabs\n> marked as ^I):\n>\n>   [...]\n>   ^I^Ihorns\n>   ^IEOF\n>\n> Which makes sense. We forgot the tab-eating \"<<-\" in the here-doc, so\n> the tab-indented EOF was not counted as the end of the input. So this\n> test is bogus and broken, and the breakage introduced by my patch is\n> only triggered because of that (which isn't to say we shouldn't\n> necessarily adjust my patch, but we definitely should fix this test).\n\nWe came to more or less the same conclusion.  With your $*\" fixed,\nthe test \"works\" as before, with the same definition of \"works\",\nbecause without your patch the file ends with <HT>EOF<LF> and with\nyour original $*<LF><HT>\" the file ends with <HT>EOF<LF> with these\nextra <LF><HT> appended, which was what made me notice, and with $*\"\nthe file ends with the same <HT>EOF<LF> as before.\n\nI've queued a fix for the original test on ta/config-set and also\namended your $*\".\n\n\n> What really surprises me is that the shell is fine with a here-doc\n> ending inside an eval.\n\nYup, it smells somewhat mis-feature-ish, doesn't it?\n\nAnyway, you do not need to respond to this message in a hurry.\n\nEnjoy your dinner ;-)\n"},{"id":"250594","messageId":"20141014004623.GA22910@peff.net","threadId":"37703","inReplyTo":"xmqq4mv71s0c.fsf@gitster.dls.corp.google.com","subject":"Re: [PATCH v2 3/3] test-lib.sh: support -x option for shell-tracing","fromName":"Jeff King","fromEmail":"peff@peff.net","sentAt":"2014-10-14T00:46:23Z","receivedAt":"2014-10-14T00:46:23Z","isPatch":true,"sender":{"key":"peff@peff.net","avatar":"https://avatars.githubusercontent.com/u/45925?v=4"},"body":"On Mon, Oct 13, 2014 at 04:14:59PM -0700, Junio C Hamano wrote:\n\n> We came to more or less the same conclusion.  With your $*\" fixed,\n> the test \"works\" as before, with the same definition of \"works\",\n> because without your patch the file ends with <HT>EOF<LF> and with\n> your original $*<LF><HT>\" the file ends with <HT>EOF<LF> with these\n> extra <LF><HT> appended, which was what made me notice, and with $*\"\n> the file ends with the same <HT>EOF<LF> as before.\n\nYeah. I think the fact that fixing the test to properly respect EOF\nrequired you to later change the line number is a good indication that\nthe test was broken in the first place. :)\n\n> I've queued a fix for the original test on ta/config-set and also\n> amended your $*\".\n\nThanks. Note that my patch still technically adds a tab in front of the\n$*. I can't imagine that would matter, but if we wanted to be extra\nconservative, we would make it:\n\n  eval \"test ... && set -x\n$*\"\n\nwith no indentation at all.\n\n> Enjoy your dinner ;-)\n\nThanks, I did. :)\n\n-Peff\n"},{"id":"250600","messageId":"543CE44E.5050009@alum.mit.edu","threadId":"37703","inReplyTo":"20141013210729.GA15969@peff.net","subject":"Re: [PATCH 0/3] \"-x\" tracing option for tests","fromName":"Michael Haggerty","fromEmail":"mhagger@alum.mit.edu","sentAt":"2014-10-14T08:52:30Z","receivedAt":"2014-10-14T08:52:30Z","isPatch":true,"sender":{"key":"mhagger@alum.mit.edu","avatar":"https://avatars.githubusercontent.com/u/119718?v=4"},"body":"On 10/13/2014 11:07 PM, Jeff King wrote:\n> On Mon, Oct 13, 2014 at 11:24:42AM -0700, Junio C Hamano wrote:\n>> [...]\n>> Is your plan to reroll the prune-mtime stuff on top of these?  The\n>> additional safety those patches would give us is valuable and they\n>> are pretty straight-forward---I was hoping to have them in the 2.2\n>> release.\n> \n> Yes, I've delayed while thinking about the issues that Michael raised.\n> There are basically two paths I see:\n> \n>   1. These do not solve all problems/races, but are a solid base and\n>      sensible path forward for further changes which we can worry about\n>      later.\n> \n>   2. There is a better way to provide prune safety, and these patches\n>      will get in the way of doing that.\n> \n> I wanted to make sure we are on path (1) and not path (2). :)\n\nFWIW I think we are on path (1).\n\nMichael\n\n-- \nMichael Haggerty\nmhagger@alum.mit.edu\n"},{"id":"250606","messageId":"20141014134415.GA20675@peff.net","threadId":"37703","inReplyTo":"543CE44E.5050009@alum.mit.edu","subject":"Re: [PATCH 0/3] \"-x\" tracing option for tests","fromName":"Jeff King","fromEmail":"peff@peff.net","sentAt":"2014-10-14T13:44:15Z","receivedAt":"2014-10-14T13:44:15Z","isPatch":true,"sender":{"key":"peff@peff.net","avatar":"https://avatars.githubusercontent.com/u/45925?v=4"},"body":"On Tue, Oct 14, 2014 at 10:52:30AM +0200, Michael Haggerty wrote:\n\n> >> Is your plan to reroll the prune-mtime stuff on top of these?  The\n> >> additional safety those patches would give us is valuable and they\n> >> are pretty straight-forward---I was hoping to have them in the 2.2\n> >> release.\n> > \n> > Yes, I've delayed while thinking about the issues that Michael raised.\n> > There are basically two paths I see:\n> > \n> >   1. These do not solve all problems/races, but are a solid base and\n> >      sensible path forward for further changes which we can worry about\n> >      later.\n> > \n> >   2. There is a better way to provide prune safety, and these patches\n> >      will get in the way of doing that.\n> > \n> > I wanted to make sure we are on path (1) and not path (2). :)\n> \n> FWIW I think we are on path (1).\n\nGood. :)\n\nI was preparing this to re-send, but I realized there is one snag. I\nmentioned that we should probably be ignoring already-broken links from\nrecent objects to missing objects. For the traversal in pack-objects, we\ncan use revs->ignore_missing_links for this. But for the one in\ngit-prune itself, we use mark_reachable, which does not respect that\noption.\n\nI think mark_reachable's traversal is essentially the same as the one in\nlist-objects.c, and the two can be merged. I'll look into that, but I\nran out of time for it tonight (er, this morning. Oops).\n\n-Peff\n"}]}