{"thread":{"id":"51862","subject":"[BUG] t7030 is flaky","startedAt":"2019-09-16T23:51:56Z","lastAt":"2019-09-17T08:54:26Z","messageCount":2,"participants":["Denton Liu","SZEDER Gábor"],"isPatch":false,"patchVersion":null,"patchTotal":null},"messages":[{"id":"382471","messageId":"20190916235149.GA96478@dentonliu-ltm.internal.salesforce.com","threadId":"51862","inReplyTo":null,"subject":"[BUG] t7030 is flaky","fromName":"Denton Liu","fromEmail":"liu.denton@gmail.com","sentAt":"2019-09-16T23:51:49Z","receivedAt":"2019-09-16T23:51:56Z","isPatch":false,"sender":{"key":"liu.denton@gmail.com","avatar":"https://avatars.githubusercontent.com/u/9620836?v=4"},"body":"Hello all,\n\nI just wanted to report that t7030 is flaky. I first noticed this on\nSzeder's Travis job[1]. I was also able to reproduce this on my Macbook\nwith gpg (GnuPG) 2.2.17 and git version 2.23.0.248.g3a9dd8fb08 (latest\nmaster) by running `./t7030-verify-tag.sh --stress`.\n\nI'll try to investigate later but for now but at the bottom of this\nemail is the trace I obtained.\n\n[1]: https://travis-ci.org/szeder/git-cooking-topics-for-travis-ci/jobs/518540359\n\n\nInitialized empty Git repository in /Users/denton.liu/projects/git/t/trash directory.t7030-verify-tag.stress-1/.git/\nexpecting success of 7030.1 'create signed tags': \n\techo 1 >file && git add file &&\n\ttest_tick && git commit -m initial &&\n\tgit tag -s -m initial initial &&\n\tgit branch side &&\n\n\techo 2 >file && test_tick && git commit -a -m second &&\n\tgit tag -s -m second second &&\n\n\tgit checkout side &&\n\techo 3 >elif && git add elif &&\n\ttest_tick && git commit -m \"third on side\" &&\n\n\tgit checkout master &&\n\ttest_tick && git merge -S side &&\n\tgit tag -s -m merge merge &&\n\n\techo 4 >file && test_tick && git commit -a -S -m \"fourth unsigned\" &&\n\tgit tag -a -m fourth-unsigned fourth-unsigned &&\n\n\ttest_tick && git commit --amend -S -m \"fourth signed\" &&\n\tgit tag -s -m fourth fourth-signed &&\n\n\techo 5 >file && test_tick && git commit -a -m \"fifth\" &&\n\tgit tag fifth-unsigned &&\n\n\tgit config commit.gpgsign true &&\n\techo 6 >file && test_tick && git commit -a -m \"sixth\" &&\n\tgit tag -a -m sixth sixth-unsigned &&\n\n\ttest_tick && git rebase -f HEAD^^ && git tag -s -m 6th sixth-signed HEAD^ &&\n\tgit tag -m seventh -s seventh-signed &&\n\n\techo 8 >file && test_tick && git commit -a -m eighth &&\n\tgit tag -uB7227189 -m eighth eighth-signed-alt\n\n++ echo 1\n++ git add file\n++ test_tick\n++ test -z ''\n++ test_tick=1112911993\n++ GIT_COMMITTER_DATE='1112911993 -0700'\n++ GIT_AUTHOR_DATE='1112911993 -0700'\n++ export GIT_COMMITTER_DATE GIT_AUTHOR_DATE\n++ git commit -m initial\n[master (root-commit) 777c62c] initial\n Author: A U Thor \n 1 file changed, 1 insertion(+)\n create mode 100644 file\n++ git tag -s -m initial initial\n++ git branch side\n++ echo 2\n++ test_tick\n++ test -z set\n++ test_tick=1112912053\n++ GIT_COMMITTER_DATE='1112912053 -0700'\n++ GIT_AUTHOR_DATE='1112912053 -0700'\n++ export GIT_COMMITTER_DATE GIT_AUTHOR_DATE\n++ git commit -a -m second\n[master 38545ae] second\n Author: A U Thor \n 1 file changed, 1 insertion(+), 1 deletion(-)\n++ git tag -s -m second second\n++ git checkout side\nSwitched to branch 'side'\n++ echo 3\n++ git add elif\n++ test_tick\n++ test -z set\n++ test_tick=1112912113\n++ GIT_COMMITTER_DATE='1112912113 -0700'\n++ GIT_AUTHOR_DATE='1112912113 -0700'\n++ export GIT_COMMITTER_DATE GIT_AUTHOR_DATE\n++ git commit -m 'third on side'\n[side 684a8f8] third on side\n Author: A U Thor \n 1 file changed, 1 insertion(+)\n create mode 100644 elif\n++ git checkout master\nSwitched to branch 'master'\n++ test_tick\n++ test -z set\n++ test_tick=1112912173\n++ GIT_COMMITTER_DATE='1112912173 -0700'\n++ GIT_AUTHOR_DATE='1112912173 -0700'\n++ export GIT_COMMITTER_DATE GIT_AUTHOR_DATE\n++ git merge -S side\nMerging:\n38545ae second\nvirtual side\nfound 1 common ancestor:\n777c62c initial\nMerge made by the 'recursive' strategy.\n elif | 1 +\n 1 file changed, 1 insertion(+)\n create mode 100644 elif\n++ git tag -s -m merge merge\n++ echo 4\n++ test_tick\n++ test -z set\n++ test_tick=1112912233\n++ GIT_COMMITTER_DATE='1112912233 -0700'\n++ GIT_AUTHOR_DATE='1112912233 -0700'\n++ export GIT_COMMITTER_DATE GIT_AUTHOR_DATE\n++ git commit -a -S -m 'fourth unsigned'\n[master 6167475] fourth unsigned\n Author: A U Thor \n 1 file changed, 1 insertion(+), 1 deletion(-)\n++ git tag -a -m fourth-unsigned fourth-unsigned\n++ test_tick\n++ test -z set\n++ test_tick=1112912293\n++ GIT_COMMITTER_DATE='1112912293 -0700'\n++ GIT_AUTHOR_DATE='1112912293 -0700'\n++ export GIT_COMMITTER_DATE GIT_AUTHOR_DATE\n++ git commit --amend -S -m 'fourth signed'\n[master d9607ab] fourth signed\n Author: A U Thor \n Date: Thu Apr 7 15:17:13 2005 -0700\n 1 file changed, 1 insertion(+), 1 deletion(-)\n++ git tag -s -m fourth fourth-signed\n++ echo 5\n++ test_tick\n++ test -z set\n++ test_tick=1112912353\n++ GIT_COMMITTER_DATE='1112912353 -0700'\n++ GIT_AUTHOR_DATE='1112912353 -0700'\n++ export GIT_COMMITTER_DATE GIT_AUTHOR_DATE\n++ git commit -a -m fifth\n[master 42b0e02] fifth\n Author: A U Thor \n 1 file changed, 1 insertion(+), 1 deletion(-)\n++ git tag fifth-unsigned\n++ git config commit.gpgsign true\n++ echo 6\n++ test_tick\n++ test -z set\n++ test_tick=1112912413\n++ GIT_COMMITTER_DATE='1112912413 -0700'\n++ GIT_AUTHOR_DATE='1112912413 -0700'\n++ export GIT_COMMITTER_DATE GIT_AUTHOR_DATE\n++ git commit -a -m sixth\n[master d964495] sixth\n Author: A U Thor \n 1 file changed, 1 insertion(+), 1 deletion(-)\n++ git tag -a -m sixth sixth-unsigned\n++ test_tick\n++ test -z set\n++ test_tick=1112912473\n++ GIT_COMMITTER_DATE='1112912473 -0700'\n++ GIT_AUTHOR_DATE='1112912473 -0700'\n++ export GIT_COMMITTER_DATE GIT_AUTHOR_DATE\n++ git rebase -f 'HEAD^^'\nCurrent branch master is up to date, rebase forced.\nFirst, rewinding head to replay your work on top of it...\nApplying: fifth\nApplying: sixth\n++ git tag -s -m 6th sixth-signed 'HEAD^'\n++ git tag -m seventh -s seventh-signed\n++ echo 8\n++ test_tick\n++ test -z set\n++ test_tick=1112912533\n++ GIT_COMMITTER_DATE='1112912533 -0700'\n++ GIT_AUTHOR_DATE='1112912533 -0700'\n++ export GIT_COMMITTER_DATE GIT_AUTHOR_DATE\n++ git commit -a -m eighth\n[master 55ae986] eighth\n Author: A U Thor \n 1 file changed, 1 insertion(+), 1 deletion(-)\n++ git tag -uB7227189 -m eighth eighth-signed-alt\nok 1 - create signed tags\n\nexpecting success of 7030.2 'create signed tags x509 ': \n\ttest_config gpg.format x509 &&\n\ttest_config user.signingkey $GIT_COMMITTER_EMAIL &&\n\techo 9 >file && test_tick && git commit -a -m \"nineth gpgsm-signed\" &&\n\tgit tag -s -m nineth nineth-signed-x509\n\n++ test_config gpg.format x509\n++ config_dir=\n++ test gpg.format = -C\n++ test_when_finished 'test_unconfig '\\''gpg.format'\\'''\n++ test 0 = 0\n++ test_cleanup='{ test_unconfig '\\''gpg.format'\\''\n\t\t} && (exit \"$eval_ret\"); eval_ret=$?; :'\n++ git config gpg.format x509\n++ test_config user.signingkey committer@example.com\n++ config_dir=\n++ test user.signingkey = -C\n++ test_when_finished 'test_unconfig '\\''user.signingkey'\\'''\n++ test 0 = 0\n++ test_cleanup='{ test_unconfig '\\''user.signingkey'\\''\n\t\t} && (exit \"$eval_ret\"); eval_ret=$?; { test_unconfig '\\''gpg.format'\\''\n\t\t} && (exit \"$eval_ret\"); eval_ret=$?; :'\n++ git config user.signingkey committer@example.com\n++ echo 9\n++ test_tick\n++ test -z set\n++ test_tick=1112912593\n++ GIT_COMMITTER_DATE='1112912593 -0700'\n++ GIT_AUTHOR_DATE='1112912593 -0700'\n++ export GIT_COMMITTER_DATE GIT_AUTHOR_DATE\n++ git commit -a -m 'nineth gpgsm-signed'\n[master 85ca5b8] nineth gpgsm-signed\n Author: A U Thor \n 1 file changed, 1 insertion(+), 1 deletion(-)\n++ git tag -s -m nineth nineth-signed-x509\n++ test_unconfig user.signingkey\n++ config_dir=\n++ test user.signingkey = -C\n++ git config --unset-all user.signingkey\n++ config_status=0\n++ case \"$config_status\" in\n++ return 0\n++ exit 0\n++ eval_ret=0\n++ test_unconfig gpg.format\n++ config_dir=\n++ test gpg.format = -C\n++ git config --unset-all gpg.format\n++ config_status=0\n++ case \"$config_status\" in\n++ return 0\n++ exit 0\n++ eval_ret=0\n++ :\nok 2 - create signed tags x509 \n\nexpecting success of 7030.3 'verify and show signatures': \n\t(\n\t\tfor tag in initial second merge fourth-signed sixth-signed seventh-signed\n\t\tdo\n\t\t\tgit verify-tag $tag 2>actual &&\n\t\t\tgrep \"Good signature from\" actual &&\n\t\t\t! grep \"BAD signature from\" actual &&\n\t\t\techo $tag OK || exit 1\n\t\tdone\n\t) &&\n\t(\n\t\tfor tag in fourth-unsigned fifth-unsigned sixth-unsigned\n\t\tdo\n\t\t\ttest_must_fail git verify-tag $tag 2>actual &&\n\t\t\t! grep \"Good signature from\" actual &&\n\t\t\t! grep \"BAD signature from\" actual &&\n\t\t\techo $tag OK || exit 1\n\t\tdone\n\t) &&\n\t(\n\t\tfor tag in eighth-signed-alt\n\t\tdo\n\t\t\tgit verify-tag $tag 2>actual &&\n\t\t\tgrep \"Good signature from\" actual &&\n\t\t\t! grep \"BAD signature from\" actual &&\n\t\t\tgrep \"not certified\" actual &&\n\t\t\techo $tag OK || exit 1\n\t\tdone\n\t)\n\n++ for tag in initial second merge fourth-signed sixth-signed seventh-signed\n++ git verify-tag initial\n++ grep 'Good signature from' actual\ngpg: Good signature from \"C O Mitter \" [ultimate]\n++ grep 'BAD signature from' actual\n++ echo initial OK\ninitial OK\n++ for tag in initial second merge fourth-signed sixth-signed seventh-signed\n++ git verify-tag second\n++ grep 'Good signature from' actual\ngpg: Good signature from \"C O Mitter \" [ultimate]\n++ grep 'BAD signature from' actual\n++ echo second OK\nsecond OK\n++ for tag in initial second merge fourth-signed sixth-signed seventh-signed\n++ git verify-tag merge\n++ grep 'Good signature from' actual\ngpg: Good signature from \"C O Mitter \" [ultimate]\n++ grep 'BAD signature from' actual\n++ echo merge OK\nmerge OK\n++ for tag in initial second merge fourth-signed sixth-signed seventh-signed\n++ git verify-tag fourth-signed\n++ grep 'Good signature from' actual\ngpg: Good signature from \"C O Mitter \" [ultimate]\n++ grep 'BAD signature from' actual\n++ echo fourth-signed OK\nfourth-signed OK\n++ for tag in initial second merge fourth-signed sixth-signed seventh-signed\n++ git verify-tag sixth-signed\n++ grep 'Good signature from' actual\ngpg: Good signature from \"C O Mitter \" [ultimate]\n++ grep 'BAD signature from' actual\n++ echo sixth-signed OK\nsixth-signed OK\n++ for tag in initial second merge fourth-signed sixth-signed seventh-signed\n++ git verify-tag seventh-signed\n++ grep 'Good signature from' actual\ngpg: Good signature from \"C O Mitter \" [ultimate]\n++ grep 'BAD signature from' actual\n++ echo seventh-signed OK\nseventh-signed OK\n++ for tag in fourth-unsigned fifth-unsigned sixth-unsigned\n++ test_must_fail git verify-tag fourth-unsigned\n++ case \"$1\" in\n++ _test_ok=\n++ git verify-tag fourth-unsigned\n++ exit_code=1\n++ test 1 -eq 0\n++ test_match_signal 13 1\n++ test 1 = 141\n++ test 1 = 269\n++ return 1\n++ test 1 -gt 129\n++ test 1 -eq 127\n++ test 1 -eq 126\n++ return 0\n++ grep 'Good signature from' actual\n++ grep 'BAD signature from' actual\n++ echo fourth-unsigned OK\nfourth-unsigned OK\n++ for tag in fourth-unsigned fifth-unsigned sixth-unsigned\n++ test_must_fail git verify-tag fifth-unsigned\n++ case \"$1\" in\n++ _test_ok=\n++ git verify-tag fifth-unsigned\n++ exit_code=1\n++ test 1 -eq 0\n++ test_match_signal 13 1\n++ test 1 = 141\n++ test 1 = 269\n++ return 1\n++ test 1 -gt 129\n++ test 1 -eq 127\n++ test 1 -eq 126\n++ return 0\n++ grep 'Good signature from' actual\n++ grep 'BAD signature from' actual\n++ echo fifth-unsigned OK\nfifth-unsigned OK\n++ for tag in fourth-unsigned fifth-unsigned sixth-unsigned\n++ test_must_fail git verify-tag sixth-unsigned\n++ case \"$1\" in\n++ _test_ok=\n++ git verify-tag sixth-unsigned\n++ exit_code=1\n++ test 1 -eq 0\n++ test_match_signal 13 1\n++ test 1 = 141\n++ test 1 = 269\n++ return 1\n++ test 1 -gt 129\n++ test 1 -eq 127\n++ test 1 -eq 126\n++ return 0\n++ grep 'Good signature from' actual\n++ grep 'BAD signature from' actual\n++ echo sixth-unsigned OK\nsixth-unsigned OK\n++ for tag in eighth-signed-alt\n++ git verify-tag eighth-signed-alt\n++ grep 'Good signature from' actual\ngpg: Good signature from \"Eris Discordia \" [unknown]\n++ grep 'BAD signature from' actual\n++ grep 'not certified' actual\ngpg: WARNING: This key is not certified with a trusted signature!\n++ echo eighth-signed-alt OK\neighth-signed-alt OK\nok 3 - verify and show signatures\n\nexpecting success of 7030.4 'verify and show signatures x509': \n\tgit verify-tag nineth-signed-x509 2>actual &&\n\tgrep \"Good signature from\" actual &&\n\t! grep \"BAD signature from\" actual &&\n\techo nineth-signed-x509 OK\n\n++ git verify-tag nineth-signed-x509\n++ grep 'Good signature from' actual\ngpgsm: Good signature from \"/CN=C O Mitter/O=Example/SN=C O/GN=Mitter\"\n++ grep 'BAD signature from' actual\n++ echo nineth-signed-x509 OK\nnineth-signed-x509 OK\nok 4 - verify and show signatures x509\n\nexpecting success of 7030.5 'detect fudged signature': \n\tgit cat-file tag seventh-signed >raw &&\n\tsed -e \"/^tag / s/seventh/7th forged/\" raw >forged1 &&\n\tgit hash-object -w -t tag forged1 >forged1.tag &&\n\ttest_must_fail git verify-tag $(cat forged1.tag) 2>actual1 &&\n\tgrep \"BAD signature from\" actual1 &&\n\t! grep \"Good signature from\" actual1\n\n++ git cat-file tag seventh-signed\n++ sed -e '/^tag / s/seventh/7th forged/' raw\n++ git hash-object -w -t tag forged1\n+++ cat forged1.tag\n++ test_must_fail git verify-tag 87979e7f1f67a2f370d47dff955a7b7a2fe8db28\n++ case \"$1\" in\n++ _test_ok=\n++ git verify-tag 87979e7f1f67a2f370d47dff955a7b7a2fe8db28\n++ exit_code=1\n++ test 1 -eq 0\n++ test_match_signal 13 1\n++ test 1 = 141\n++ test 1 = 269\n++ return 1\n++ test 1 -gt 129\n++ test 1 -eq 127\n++ test 1 -eq 126\n++ return 0\n++ grep 'BAD signature from' actual1\ngpg: BAD signature from \"C O Mitter \" [ultimate]\n++ grep 'Good signature from' actual1\nok 5 - detect fudged signature\n\nexpecting success of 7030.6 'verify signatures with --raw': \n\t(\n\t\tfor tag in initial second merge fourth-signed sixth-signed seventh-signed\n\t\tdo\n\t\t\tgit verify-tag --raw $tag 2>actual &&\n\t\t\tgrep \"GOODSIG\" actual &&\n\t\t\t! grep \"BADSIG\" actual &&\n\t\t\techo $tag OK || exit 1\n\t\tdone\n\t) &&\n\t(\n\t\tfor tag in fourth-unsigned fifth-unsigned sixth-unsigned\n\t\tdo\n\t\t\ttest_must_fail git verify-tag --raw $tag 2>actual &&\n\t\t\t! grep \"GOODSIG\" actual &&\n\t\t\t! grep \"BADSIG\" actual &&\n\t\t\techo $tag OK || exit 1\n\t\tdone\n\t) &&\n\t(\n\t\tfor tag in eighth-signed-alt\n\t\tdo\n\t\t\tgit verify-tag --raw $tag 2>actual &&\n\t\t\tgrep \"GOODSIG\" actual &&\n\t\t\t! grep \"BADSIG\" actual &&\n\t\t\tgrep \"TRUST_UNDEFINED\" actual &&\n\t\t\techo $tag OK || exit 1\n\t\tdone\n\t)\n\n++ for tag in initial second merge fourth-signed sixth-signed seventh-signed\n++ git verify-tag --raw initial\n++ grep GOODSIG actual\n[GNUPG:] GOODSIG 13B6F51ECDDE430D C O Mitter \n++ grep BADSIG actual\n++ echo initial OK\ninitial OK\n++ for tag in initial second merge fourth-signed sixth-signed seventh-signed\n++ git verify-tag --raw second\n++ grep GOODSIG actual\n[GNUPG:] GOODSIG 13B6F51ECDDE430D C O Mitter \n++ grep BADSIG actual\n++ echo second OK\nsecond OK\n++ for tag in initial second merge fourth-signed sixth-signed seventh-signed\n++ git verify-tag --raw merge\n++ grep GOODSIG actual\n[GNUPG:] GOODSIG 13B6F51ECDDE430D C O Mitter \n++ grep BADSIG actual\n++ echo merge OK\nmerge OK\n++ for tag in initial second merge fourth-signed sixth-signed seventh-signed\n++ git verify-tag --raw fourth-signed\n++ grep GOODSIG actual\n[GNUPG:] GOODSIG 13B6F51ECDDE430D C O Mitter \n++ grep BADSIG actual\n++ echo fourth-signed OK\nfourth-signed OK\n++ for tag in initial second merge fourth-signed sixth-signed seventh-signed\n++ git verify-tag --raw sixth-signed\n++ grep GOODSIG actual\n[GNUPG:] GOODSIG 13B6F51ECDDE430D C O Mitter \n++ grep BADSIG actual\n++ echo sixth-signed OK\nsixth-signed OK\n++ for tag in initial second merge fourth-signed sixth-signed seventh-signed\n++ git verify-tag --raw seventh-signed\n++ grep GOODSIG actual\n[GNUPG:] GOODSIG 13B6F51ECDDE430D C O Mitter \n++ grep BADSIG actual\n++ echo seventh-signed OK\nseventh-signed OK\n++ for tag in fourth-unsigned fifth-unsigned sixth-unsigned\n++ test_must_fail git verify-tag --raw fourth-unsigned\n++ case \"$1\" in\n++ _test_ok=\n++ git verify-tag --raw fourth-unsigned\n++ exit_code=1\n++ test 1 -eq 0\n++ test_match_signal 13 1\n++ test 1 = 141\n++ test 1 = 269\n++ return 1\n++ test 1 -gt 129\n++ test 1 -eq 127\n++ test 1 -eq 126\n++ return 0\n++ grep GOODSIG actual\n++ grep BADSIG actual\n++ echo fourth-unsigned OK\nfourth-unsigned OK\n++ for tag in fourth-unsigned fifth-unsigned sixth-unsigned\n++ test_must_fail git verify-tag --raw fifth-unsigned\n++ case \"$1\" in\n++ _test_ok=\n++ git verify-tag --raw fifth-unsigned\n++ exit_code=1\n++ test 1 -eq 0\n++ test_match_signal 13 1\n++ test 1 = 141\n++ test 1 = 269\n++ return 1\n++ test 1 -gt 129\n++ test 1 -eq 127\n++ test 1 -eq 126\n++ return 0\n++ grep GOODSIG actual\n++ grep BADSIG actual\n++ echo fifth-unsigned OK\nfifth-unsigned OK\n++ for tag in fourth-unsigned fifth-unsigned sixth-unsigned\n++ test_must_fail git verify-tag --raw sixth-unsigned\n++ case \"$1\" in\n++ _test_ok=\n++ git verify-tag --raw sixth-unsigned\n++ exit_code=1\n++ test 1 -eq 0\n++ test_match_signal 13 1\n++ test 1 = 141\n++ test 1 = 269\n++ return 1\n++ test 1 -gt 129\n++ test 1 -eq 127\n++ test 1 -eq 126\n++ return 0\n++ grep GOODSIG actual\n++ grep BADSIG actual\n++ echo sixth-unsigned OK\nsixth-unsigned OK\n++ for tag in eighth-signed-alt\n++ git verify-tag --raw eighth-signed-alt\n++ grep GOODSIG actual\n[GNUPG:] GOODSIG 65A0EEA02E30CAD7 Eris Discordia \n++ grep BADSIG actual\n++ grep TRUST_UNDEFINED actual\n[GNUPG:] TRUST_UNDEFINED 0 pgp\n++ echo eighth-signed-alt OK\neighth-signed-alt OK\nok 6 - verify signatures with --raw\n\nexpecting success of 7030.7 'verify signatures with --raw x509': \n\tgit verify-tag --raw nineth-signed-x509 2>actual &&\n\tgrep \"GOODSIG\" actual &&\n\t! grep \"BADSIG\" actual &&\n\techo nineth-signed-x509 OK\n\n++ git verify-tag --raw nineth-signed-x509\n++ grep GOODSIG actual\n[GNUPG:] GOODSIG F8BF62E0693D0694816377099909C779FA23FD65 /CN=C O Mitter/O=Example/SN=C O/GN=Mitter\n++ grep BADSIG actual\n++ echo nineth-signed-x509 OK\nnineth-signed-x509 OK\nok 7 - verify signatures with --raw x509\n\nexpecting success of 7030.8 'verify multiple tags': \n\ttags=\"fourth-signed sixth-signed seventh-signed\" &&\n\tfor i in $tags\n\tdo\n\t\tgit verify-tag -v --raw $i || return 1\n\tdone >expect.stdout 2>expect.stderr.1 &&\n\tgrep \"^.GNUPG:.\" expect.stderr &&\n\tgit verify-tag -v --raw $tags >actual.stdout 2>actual.stderr.1 &&\n\tgrep \"^.GNUPG:.\" actual.stderr &&\n\ttest_cmp expect.stdout actual.stdout &&\n\ttest_cmp expect.stderr actual.stderr\n\n++ tags='fourth-signed sixth-signed seventh-signed'\n++ grep '^.GNUPG:.'\n++ git verify-tag -v --raw fourth-signed sixth-signed seventh-signed\n++ grep '^.GNUPG:.'\n++ test_cmp expect.stdout actual.stdout\n++ diff -u expect.stdout actual.stdout\n++ test_cmp expect.stderr actual.stderr\n++ diff -u expect.stderr actual.stderr\nok 8 - verify multiple tags\n\nexpecting success of 7030.9 'verify multiple tags x509': \n\ttags=\"seventh-signed nineth-signed-x509\" &&\n\tfor i in $tags\n\tdo\n\t\tgit verify-tag -v --raw $i || return 1\n\tdone >expect.stdout 2>expect.stderr.1 &&\n\tgrep \"^.GNUPG:.\" expect.stderr &&\n\tgit verify-tag -v --raw $tags >actual.stdout 2>actual.stderr.1 &&\n\tgrep \"^.GNUPG:.\" actual.stderr &&\n\ttest_cmp expect.stdout actual.stdout &&\n\ttest_cmp expect.stderr actual.stderr\n\n++ tags='seventh-signed nineth-signed-x509'\n++ grep '^.GNUPG:.'\n++ git verify-tag -v --raw seventh-signed nineth-signed-x509\n++ grep '^.GNUPG:.'\n++ test_cmp expect.stdout actual.stdout\n++ diff -u expect.stdout actual.stdout\n++ test_cmp expect.stderr actual.stderr\n++ diff -u expect.stderr actual.stderr\n--- expect.stderr\t2019-09-16 23:48:06.000000000 +0000\n+++ actual.stderr\t2019-09-16 23:48:06.000000000 +0000\n@@ -8,7 +8,6 @@\n [GNUPG:] TRUST_ULTIMATE 0 pgp\n [GNUPG:] NEWSIG\n [GNUPG:] VERIFICATION_COMPLIANCE_MODE 23\n-[GNUPG:] PROGRESS starting_agent ? 0 0\n [GNUPG:] GOODSIG F8BF62E0693D0694816377099909C779FA23FD65 /CN=C O Mitter/O=Example/SN=C O/GN=Mitter\n [GNUPG:] VALIDSIG F8BF62E0693D0694816377099909C779FA23FD65 2019-09-16 20190916T234804 30000101T000000 0 0 1 8 00\n [GNUPG:] TRUST_FULLY 0 shell\nerror: last command exited with $?=1\nnot ok 9 - verify multiple tags x509\n#\t\n#\t\ttags=\"seventh-signed nineth-signed-x509\" &&\n#\t\tfor i in $tags\n#\t\tdo\n#\t\t\tgit verify-tag -v --raw $i || return 1\n#\t\tdone >expect.stdout 2>expect.stderr.1 &&\n#\t\tgrep \"^.GNUPG:.\" expect.stderr &&\n#\t\tgit verify-tag -v --raw $tags >actual.stdout 2>actual.stderr.1 &&\n#\t\tgrep \"^.GNUPG:.\" actual.stderr &&\n#\t\ttest_cmp expect.stdout actual.stdout &&\n#\t\ttest_cmp expect.stderr actual.stderr\n#\t\n"},{"id":"382476","messageId":"20190917085325.GG6190@szeder.dev","threadId":"51862","inReplyTo":"20190916235149.GA96478@dentonliu-ltm.internal.salesforce.com","subject":"Re: [BUG] t7030 is flaky","fromName":"SZEDER Gábor","fromEmail":"szeder.dev@gmail.com","sentAt":"2019-09-17T08:53:25Z","receivedAt":"2019-09-17T08:54:26Z","isPatch":false,"sender":{"key":"szeder.dev@gmail.com","avatar":"https://avatars.githubusercontent.com/u/116324?v=4"},"body":"[Cc-ing brian, because I can vaguely remember (or misremember?) that\nhe cares about GnuPG.]\n\nOn Mon, Sep 16, 2019 at 04:51:49PM -0700, Denton Liu wrote:\n> I just wanted to report that t7030 is flaky. I first noticed this on\n> Szeder's Travis job[1]. I was also able to reproduce this on my Macbook\n> with gpg (GnuPG) 2.2.17 and git version 2.23.0.248.g3a9dd8fb08 (latest\n> master) by running `./t7030-verify-tag.sh --stress`.\n\nIt's not only t7030, but verifying multiple signatures at once in\nmacOS and GnuPG 2.2, i.e. these tests fail occasionally:\n\n t7030-verify-tag.sh:\n 8 - verify multiple tags [2]\n 9 - verify multiple tags x509 [1]\n\n t7004-tag.sh:\n 92 - verifying two signed tags in one command should succeed [3]\n (nowadays it's the 94th test)\n\nNote that these are all about tags; as far as I can tell we have no\ntests that verify multiple signed commits at once.\n\nI tried to reproduce it on Linux, with GnuPG v1.4 and v2.2, no luck so\nfar.\n\n> I'll try to investigate later but for now but at the bottom of this\n> email is the trace I obtained.\n> \n> [1]: https://travis-ci.org/szeder/git-cooking-topics-for-travis-ci/jobs/518540359\n\n[2] https://travis-ci.org/szeder/git-cooking-topics-for-travis-ci/jobs/514969530#L3183\n[3] https://travis-ci.org/szeder/git-cooking-topics-for-travis-ci/jobs/487665767#L3891\n\n> expecting success of 7030.9 'verify multiple tags x509': \n> \ttags=\"seventh-signed nineth-signed-x509\" &&\n> \tfor i in $tags\n> \tdo\n> \t\tgit verify-tag -v --raw $i || return 1\n> \tdone >expect.stdout 2>expect.stderr.1 &&\n\nSidenote: oh, look, a shell loop with its standard error redirected to\na file. Normally we shouldn't do that, because with '-x' tracing it\nrecords the trace output of the commands executed inside the loop as\nwell. Luckily, in this case it's not a big issue, because:\n\n> \tgrep \"^.GNUPG:.\" expect.stderr &&\n\nthis 'grep' throws away all that trace, so it doesn't interfere with\nthe test's correctness.\n\n> \tgit verify-tag -v --raw $tags >actual.stdout 2>actual.stderr.1 &&\n> \tgrep \"^.GNUPG:.\" actual.stderr &&\n> \ttest_cmp expect.stdout actual.stdout &&\n> \ttest_cmp expect.stderr actual.stderr\n> \n> ++ tags='seventh-signed nineth-signed-x509'\n> ++ grep '^.GNUPG:.'\n> ++ git verify-tag -v --raw seventh-signed nineth-signed-x509\n> ++ grep '^.GNUPG:.'\n> ++ test_cmp expect.stdout actual.stdout\n> ++ diff -u expect.stdout actual.stdout\n> ++ test_cmp expect.stderr actual.stderr\n> ++ diff -u expect.stderr actual.stderr\n> --- expect.stderr\t2019-09-16 23:48:06.000000000 +0000\n> +++ actual.stderr\t2019-09-16 23:48:06.000000000 +0000\n> @@ -8,7 +8,6 @@\n> [GNUPG:] TRUST_ULTIMATE 0 pgp\n> [GNUPG:] NEWSIG\n> [GNUPG:] VERIFICATION_COMPLIANCE_MODE 23\n> -[GNUPG:] PROGRESS starting_agent ? 0 0\n> [GNUPG:] GOODSIG F8BF62E0693D0694816377099909C779FA23FD65 /CN=C O Mitter/O=Example/SN=C O/GN=Mitter\n> [GNUPG:] VALIDSIG F8BF62E0693D0694816377099909C779FA23FD65 2019-09-16 20190916T234804 30000101T000000 0 0 1 8 00\n> [GNUPG:] TRUST_FULLY 0 shell\n\nThis is interesting, I only remember these tests fail because the 'git\nverify-tag' command failed. I thought that the error message shown by\n'git verify-tag' might give a hint about what went wrong, but\n'actual.stderr.1' (i.e. its original stderr) contains this:\n\n [GNUPG:] NEWSIG committer@example.com\n [GNUPG:] KEY_CONSIDERED 73D758744BE721698EC54E8713B6F51ECDDE430D 0\n [GNUPG:] SIG_ID 2Eg0F1yiJ07HcOjvjO96x2wJvvs 2019-09-17 1568707912\n [GNUPG:] KEY_CONSIDERED 73D758744BE721698EC54E8713B6F51ECDDE430D 0\n [GNUPG:] GOODSIG 13B6F51ECDDE430D C O Mitter \n [GNUPG:] VALIDSIG 73D758744BE721698EC54E8713B6F51ECDDE430D 2019-09-17 1568707912 0 4 0 17 2 00 73D758744BE721698EC54E8713B6F51ECDDE430D\n [GNUPG:] KEY_CONSIDERED 73D758744BE721698EC54E8713B6F51ECDDE430D 0\n [GNUPG:] TRUST_ULTIMATE 0 pgp\n [GNUPG:] NEWSIG\n [GNUPG:] VERIFICATION_COMPLIANCE_MODE 23\n [GNUPG:] PROGRESS starting_agent ? 0 0\n [GNUPG:] GOODSIG F8BF62E0693D0694816377099909C779FA23FD65 /CN=C O Mitter/O=Example/SN=C O/GN=Mitter\n [GNUPG:] VALIDSIG F8BF62E0693D0694816377099909C779FA23FD65 2019-09-17 20190917T081152 30000101T000000 0 0 1 8 00\n [GNUPG:] TRUST_FULLY 0 shell\n\nIOW no error message from 'git verify-tag' itself whatsoever, only\noutput from GnuPG, which, to my untrained eyes, looks OK.\n\n> error: last command exited with $?=1\n> not ok 9 - verify multiple tags x509\n> #\t\n> #\t\ttags=\"seventh-signed nineth-signed-x509\" &&\n> #\t\tfor i in $tags\n> #\t\tdo\n> #\t\t\tgit verify-tag -v --raw $i || return 1\n> #\t\tdone >expect.stdout 2>expect.stderr.1 &&\n> #\t\tgrep \"^.GNUPG:.\" expect.stderr &&\n> #\t\tgit verify-tag -v --raw $tags >actual.stdout 2>actual.stderr.1 &&\n> #\t\tgrep \"^.GNUPG:.\" actual.stderr &&\n> #\t\ttest_cmp expect.stdout actual.stdout &&\n> #\t\ttest_cmp expect.stderr actual.stderr\n> #\t\n"}]}