# [PATCH 0/1] t7406: avoid failures solely due to timing issues 7 messages from 2018-07-23 to 2018-07-24. Participants: Johannes Schindelin via GitGitGadget, Junio C Hamano, Stefan Beller, Torsten Bögershausen. Thread: https://gitlist.dev/t/48940 ## Johannes Schindelin via GitGitGadget, 2018-07-23 13:39 Subject: [PATCH 0/1] t7406: avoid failures solely due to timing issues Message-ID: URL: https://gitlist.dev/e/pull.12.git.gitgitgadget%40gmail.com ``` This fixes a regression test that produces false positives occasionally: https://git-for-windows.visualstudio.com/git/_build/results?buildId=14035&view=logs Johannes Schindelin (1): t7406: avoid failures solely due to timing issues t/t7406-submodule-update.sh | 11 ++++++----- 1 file changed, 6 insertions(+), 5 deletions(-) base-commit: b7bd9486b055c3f967a870311e704e3bb0654e4f Published-As: https://github.com/gitgitgadget/git/releases/tags/pr-12%2Fdscho%2Fmore-robust-t7406-v1 Fetch-It-Via: git fetch https://github.com/gitgitgadget/git pr-12/dscho/more-robust-t7406-v1 Pull-Request: https://github.com/gitgitgadget/git/pull/12 -- gitgitgadget ``` ## Johannes Schindelin via GitGitGadget, 2018-07-23 13:39 Subject: [PATCH 1/1] t7406: avoid failures solely due to timing issues Message-ID: <78f7a5e4baae162d1dff18701a25903b304adf9e.1532353179.git.gitgitgadget@gmail.com> URL: https://gitlist.dev/e/78f7a5e4baae162d1dff18701a25903b304adf9e.1532353179.git.gitgitgadget%40gmail.com In-Reply-To: ``` From: Johannes Schindelin Regression tests are automated tests which try to ensure a specific behavior. The idea is: if the test case fails, the behavior indicated in the test case's title regressed. If a regression test that fails, even occasionally, for any reason other than to indicate the particular regression(s) it tries to catch, it is less useful than when it really only fails when there is a bug in the (non-test) code that needs to be fixed. In the instance of the test case "submodule update --init --recursive from subdirectory" of the script t7406-submodule-update.sh, the exact output of a recursive clone is compared with a pre-generated one. And this is a racy test because the structure of the submodules only guarantees a *partial* order. The 'none' and the 'rebasing' submodules *can* be cloned in any order, which means that a mismatch with the hard-coded order does not necessarily indicate a bug in the tested code. See for example: https://git-for-windows.visualstudio.com/git/_build/results?buildId=14035&view=logs To prevent such false positives from unnecessarily costing time when investigating test failures, let's take the exact order of the lines out of the equation by sorting them before comparing them. This test script seems not to have any more test cases that try to verify any specific order in which recursive clones process the submodules, therefore this is the only test case that is changed in this manner. Signed-off-by: Johannes Schindelin --- t/t7406-submodule-update.sh | 11 ++++++----- 1 file changed, 6 insertions(+), 5 deletions(-) diff --git a/t/t7406-submodule-update.sh b/t/t7406-submodule-update.sh index 9e0d31700..4937ebb67 100755 --- a/t/t7406-submodule-update.sh +++ b/t/t7406-submodule-update.sh @@ -115,17 +115,17 @@ Submodule path '../super/submodule': checked out '$submodulesha1' EOF cat <expect2 +Cloning into '$pwd/recursivesuper/super/merging'... +Cloning into '$pwd/recursivesuper/super/none'... +Cloning into '$pwd/recursivesuper/super/rebasing'... +Cloning into '$pwd/recursivesuper/super/submodule'... Submodule 'merging' ($pwd/merging) registered for path '../super/merging' Submodule 'none' ($pwd/none) registered for path '../super/none' Submodule 'rebasing' ($pwd/rebasing) registered for path '../super/rebasing' Submodule 'submodule' ($pwd/submodule) registered for path '../super/submodule' -Cloning into '$pwd/recursivesuper/super/merging'... done. -Cloning into '$pwd/recursivesuper/super/none'... done. -Cloning into '$pwd/recursivesuper/super/rebasing'... done. -Cloning into '$pwd/recursivesuper/super/submodule'... done. EOF @@ -137,7 +137,8 @@ test_expect_success 'submodule update --init --recursive from subdirectory' ' git submodule update --init --recursive ../super >../../actual 2>../../actual2 ) && test_i18ncmp expect actual && - test_i18ncmp expect2 actual2 + sort actual2 >actual2.sorted && + test_i18ncmp expect2 actual2.sorted ' cat <expect2 -- gitgitgadget ``` ## Junio C Hamano, 2018-07-23 19:10 Subject: Re: [PATCH 0/1] t7406: avoid failures solely due to timing issues Message-ID: URL: https://gitlist.dev/e/xmqqr2jt6a5b.fsf%40gitster-ct.c.googlers.com In-Reply-To: ``` "Johannes Schindelin via GitGitGadget" writes: > This fixes a regression test that produces false positives occasionally: https://git-for-windows.visualstudio.com/git/_build/results?buildId=14035&view=logs > [jc: forwrding to Torsten for <208b2ede-4833-f062-16f2-f35b8a8ce099@web.de>] > Johannes Schindelin (1): > t7406: avoid failures solely due to timing issues > > t/t7406-submodule-update.sh | 11 ++++++----- > 1 file changed, 6 insertions(+), 5 deletions(-) > > > base-commit: b7bd9486b055c3f967a870311e704e3bb0654e4f > Published-As: https://github.com/gitgitgadget/git/releases/tags/pr-12%2Fdscho%2Fmore-robust-t7406-v1 > Fetch-It-Via: git fetch https://github.com/gitgitgadget/git pr-12/dscho/more-robust-t7406-v1 > Pull-Request: https://github.com/gitgitgadget/git/pull/12 ``` ## Junio C Hamano, 2018-07-23 19:14 Subject: Re: [PATCH 1/1] t7406: avoid failures solely due to timing issues Message-ID: URL: https://gitlist.dev/e/xmqqmuuh69xx.fsf%40gitster-ct.c.googlers.com In-Reply-To: <78f7a5e4baae162d1dff18701a25903b304adf9e.1532353179.git.gitgitgadget@gmail.com> ``` "Johannes Schindelin via GitGitGadget" writes: > To prevent such false positives from unnecessarily costing time when > investigating test failures, let's take the exact order of the lines out > of the equation by sorting them before comparing them. > ... > cat <expect2 > +Cloning into '$pwd/recursivesuper/super/merging'... > +Cloning into '$pwd/recursivesuper/super/none'... > +Cloning into '$pwd/recursivesuper/super/rebasing'... > +Cloning into '$pwd/recursivesuper/super/submodule'... > Submodule 'merging' ($pwd/merging) registered for path '../super/merging' > Submodule 'none' ($pwd/none) registered for path '../super/none' > Submodule 'rebasing' ($pwd/rebasing) registered for path '../super/rebasing' > Submodule 'submodule' ($pwd/submodule) registered for path '../super/submodule' Thanks. It obviously goes in the right direction to loosen the ordering requirement that fundamentally cannot be met, as the log message cleanly analizes. Do we know that the write(2)s that show these lines are atomic, or are we merely lucky that we don't see them intermixed in the middle of lines (sbeller cc'ed). I _think_ they are but just wanted to double check. ``` ## Stefan Beller, 2018-07-23 20:53 Subject: Re: [PATCH 1/1] t7406: avoid failures solely due to timing issues Message-ID: URL: https://gitlist.dev/e/CAGZ79kag%3DYC6PxOnBbVAqY92dNd5yuqfvash-oPVrEktowNbVA%40mail.gmail.com In-Reply-To: ``` On Mon, Jul 23, 2018 at 12:14 PM Junio C Hamano wrote: > > "Johannes Schindelin via GitGitGadget" > writes: > > > To prevent such false positives from unnecessarily costing time when > > investigating test failures, let's take the exact order of the lines out > > of the equation by sorting them before comparing them. > > ... > > cat <expect2 > > +Cloning into '$pwd/recursivesuper/super/merging'... > > +Cloning into '$pwd/recursivesuper/super/none'... > > +Cloning into '$pwd/recursivesuper/super/rebasing'... > > +Cloning into '$pwd/recursivesuper/super/submodule'... > > Submodule 'merging' ($pwd/merging) registered for path '../super/merging' > > Submodule 'none' ($pwd/none) registered for path '../super/none' > > Submodule 'rebasing' ($pwd/rebasing) registered for path '../super/rebasing' > > Submodule 'submodule' ($pwd/submodule) registered for path '../super/submodule' > > Thanks. It obviously goes in the right direction to loosen the > ordering requirement that fundamentally cannot be met, as the log > message cleanly analizes. > > Do we know that the write(2)s that show these lines are atomic, or > are we merely lucky that we don't see them intermixed in the middle > of lines (sbeller cc'ed). I _think_ they are but just wanted to > double check. Not just the lines, but the whole message per submodule (i.e. the "Cloning... " lione and its accompanying "done") is one atomic unit. These messages are from processes invoked via run_processes_parallel (in run-command.h), which buffers all output per process. This test was last touched in c66410ed32a (submodule init: redirect stdout to stderr, 2016-05-02), merged as f2c96ceb57a (Merge branch 'sb/submodule-init', 2016-05-17) The parallelizing effort was made before that (2335b870fa7 (submodule update: expose parallelism to the user, 2016-02-29) via bdebbeb3346 (Merge branch 'sb/submodule-parallel-update', 2016-04-06)), but did not review existing tests for the newly introduced raciness. Thanks for the fix! Stefan ``` ## Junio C Hamano, 2018-07-23 21:31 Subject: Re: [PATCH 1/1] t7406: avoid failures solely due to timing issues Message-ID: URL: https://gitlist.dev/e/xmqqlga14p16.fsf%40gitster-ct.c.googlers.com In-Reply-To: ``` Stefan Beller writes: > This test was last touched in c66410ed32a (submodule init: > redirect stdout to stderr, 2016-05-02), merged as f2c96ceb57a > (Merge branch 'sb/submodule-init', 2016-05-17) > > The parallelizing effort was made before that > (2335b870fa7 (submodule update: expose parallelism to the > user, 2016-02-29) via bdebbeb3346 (Merge branch > 'sb/submodule-parallel-update', 2016-04-06)), but did not > review existing tests for the newly introduced raciness. Ah, that explains what I was scratching my head about. I somehow thought that the parallel update broke an otherwise working test written back in the serial days, but it seems it was the other way around. The test was simply careless. Nice to have the two-year old issue fixed. Thanks, all. ``` ## Torsten Bögershausen, 2018-07-24 09:00 Subject: Re: [PATCH 0/1] t7406: avoid failures solely due to timing issues Message-ID: <20180724090005.GA25260@tor.lan> URL: https://gitlist.dev/e/20180724090005.GA25260%40tor.lan In-Reply-To: ``` On Mon, Jul 23, 2018 at 12:10:24PM -0700, Junio C Hamano wrote: > "Johannes Schindelin via GitGitGadget" > writes: > > > This fixes a regression test that produces false positives occasionally: https://git-for-windows.visualstudio.com/git/_build/results?buildId=14035&view=logs > > > > [jc: forwrding to Torsten for <208b2ede-4833-f062-16f2-f35b8a8ce099@web.de>] Yes, thanks for a "fantastic fast fix" and the integration. I downloaded and tested it OK (under MacOS) this morning. ```