diff mbox series

[1/2] worktree: send "chatty" messages to stderr

Message ID 20211203034420.47447-2-sunshine@sunshineco.com (mailing list archive)
State Accepted
Commit da8fb6be5594b4a06ef2cc2ff7a5363a6fac2b5a
Headers show
Series worktree: fix incorrectly-ordered messages on Windows | expand

Commit Message

Eric Sunshine Dec. 3, 2021, 3:44 a.m. UTC
The order in which the stdout and stderr streams are flushed is not
guaranteed to be the same across platforms or `libc` implementations.
This lack of determinism can lead to anomalous and potentially confusing
output if normal (stdout) output is flushed after error (stderr) output.
For instance, the following output which clearly indicates a failure due
to a fatal error:

    % git worktree add ../foo bar
    Preparing worktree (checking out 'bar')
    fatal: 'bar' is already checked out at '.../wherever'

has been reported[1] on Microsoft Windows to appear as:

    % git worktree add ../foo bar
    fatal: 'bar' is already checked out at '.../wherever'
    Preparing worktree (checking out 'bar')

which may confuse the reader into thinking that the command somehow
recovered and ran to completion despite the error.

This problem crops up because the "chatty" status message "Preparing
worktree" is sent to stdout, whereas the "fatal" error message is sent
to stderr. One way to fix this would be to flush stdout manually before
git-worktree reports any errors to stderr.

However, common practice in Git is for "chatty" messages to be sent to
stderr. Therefore, a more appropriate fix is to adjust git-worktree to
conform to that practice by sending its "chatty" messages to stderr
rather than stdout as is currently the case.

There may be concern that relocating messages from stdout to stderr
could break existing tooling, however, these messages are already
internationalized, thus are unstable. And, indeed, the "Preparing
worktree" message has already been the subject of somewhat significant
changes in 2c27002a0a (worktree: improve message when creating a new
worktree, 2018-04-24). Moreover, there is existing precedent, such as
68b939b2f0 (clone: send diagnostic messages to stderr, 2013-09-18) which
likewise relocated "chatty" messages from stdout to stderr for
git-clone.

[1]: https://lore.kernel.org/git/CA+34VNLj6VB1kCkA=MfM7TZR+6HgqNi5-UaziAoCXacSVkch4A@mail.gmail.com/T/

Reported-by: Baruch Burstein <bmburstein@gmail.com>
Signed-off-by: Eric Sunshine <sunshine@sunshineco.com>
---
 builtin/worktree.c         | 14 +++++++-------
 t/t2401-worktree-prune.sh  | 14 +++++++-------
 t/t2402-worktree-list.sh   |  2 +-
 t/t2406-worktree-repair.sh | 30 ++++++++++++------------------
 4 files changed, 27 insertions(+), 33 deletions(-)

Comments

Ævar Arnfjörð Bjarmason Dec. 3, 2021, 9:17 a.m. UTC | #1
On Thu, Dec 02 2021, Eric Sunshine wrote:

> The order in which the stdout and stderr streams are flushed is not
> guaranteed to be the same across platforms or `libc` implementations.
> This lack of determinism can lead to anomalous and potentially confusing
> output if normal (stdout) output is flushed after error (stderr) output.
> For instance, the following output which clearly indicates a failure due
> to a fatal error:
>
>     % git worktree add ../foo bar
>     Preparing worktree (checking out 'bar')
>     fatal: 'bar' is already checked out at '.../wherever'
>
> has been reported[1] on Microsoft Windows to appear as:
>
>     % git worktree add ../foo bar
>     fatal: 'bar' is already checked out at '.../wherever'
>     Preparing worktree (checking out 'bar')

Makes sense.

>  test_expect_success 'repair incorrect gitdir' '
> @@ -141,10 +139,9 @@ test_expect_success 'repair incorrect gitdir' '
>  	git worktree add --detach orig &&
>  	sed s,orig/\.git$,moved/.git, .git/worktrees/orig/gitdir >expect &&
>  	mv orig moved &&
> -	git worktree repair moved >out 2>err &&
> +	git worktree repair moved 2>err &&
>  	test_cmp expect .git/worktrees/orig/gitdir &&
> -	test_i18ngrep "gitdir incorrect" out &&
> -	test_must_be_empty err
> +	test_i18ngrep "gitdir incorrect" err
>  '

This is just a "for bonus points", but maybe we could/should while we're
at it harden and make the tests more exhaustive by checking the full
output of both, e.g.

	cat >actual.out <<-\EOF &&
	Preparing worktree (checking out 'bar')
	EOF
	cat >actual.err <<-\EOF &&
	fatal: 'bar' is already checked out at '.../wherever'
	EOF
        <cmd> [...]
	test_cmp expect.out actual.out &&
	test_cmp expect.err actual.err

Doesn't need a re-roll etc., just if you're interested... :)
Eric Sunshine Dec. 3, 2021, 1:07 p.m. UTC | #2
On Fri, Dec 3, 2021 at 4:19 AM Ævar Arnfjörð Bjarmason <avarab@gmail.com> wrote:
> On Thu, Dec 02 2021, Eric Sunshine wrote:
> >       git worktree add --detach orig &&
> >       sed s,orig/\.git$,moved/.git, .git/worktrees/orig/gitdir >expect &&
> >       mv orig moved &&
> > -     git worktree repair moved >out 2>err &&
> > +     git worktree repair moved 2>err &&
> >       test_cmp expect .git/worktrees/orig/gitdir &&
> > -     test_i18ngrep "gitdir incorrect" out &&
> > -     test_must_be_empty err
> > +     test_i18ngrep "gitdir incorrect" err
> >  '
>
> This is just a "for bonus points", but maybe we could/should while we're
> at it harden and make the tests more exhaustive by checking the full
> output of both, e.g.
>
>         cat >actual.out <<-\EOF &&
>         Preparing worktree (checking out 'bar')
>         EOF
>         cat >actual.err <<-\EOF &&
>         fatal: 'bar' is already checked out at '.../wherever'
>         EOF
>         <cmd> [...]
>         test_cmp expect.out actual.out &&
>         test_cmp expect.err actual.err
>
> Doesn't need a re-roll etc., just if you're interested... :)

To be clear, with the application of the current patch, both of those
messages would need to be in the `actual.err` file, and `actual.out`
would be empty; not one message in each file as in your snippet.

That aside, there's still potentially output which is outside the
control of git-worktree. In the case of this particular negative test,
your suggestion should work, but for a positive test, it would be
harder and uglier (though, of course, not impossible). For instance,
for a successful `git worktree add`, the output is:

    Preparing worktree (new branch 'foobar')
    Updating files: 100% (3993/3993), done.
    HEAD is now at abe6bb3905 Gobbledygook

The subsequent lines come from git-reset (which, by the way, is
sending "HEAD is now at" to stdout, though they probably should be on
stderr, but that's a separate issue).

Anyhow, such a change to the tests should be a separate topic. The
user-facing problem addressed by the current patch series need not be
held up by a behind-the-scenes change to testing.
diff mbox series

Patch

diff --git a/builtin/worktree.c b/builtin/worktree.c
index d22ece93e1..a57fcd0f3c 100644
--- a/builtin/worktree.c
+++ b/builtin/worktree.c
@@ -72,7 +72,7 @@  static void delete_worktrees_dir_if_empty(void)
 static void prune_worktree(const char *id, const char *reason)
 {
 	if (show_only || verbose)
-		printf_ln(_("Removing %s/%s: %s"), "worktrees", id, reason);
+		fprintf_ln(stderr, _("Removing %s/%s: %s"), "worktrees", id, reason);
 	if (!show_only)
 		delete_git_dir(id);
 }
@@ -418,24 +418,24 @@  static void print_preparing_worktree_line(int detach,
 	if (force_new_branch) {
 		struct commit *commit = lookup_commit_reference_by_name(new_branch);
 		if (!commit)
-			printf_ln(_("Preparing worktree (new branch '%s')"), new_branch);
+			fprintf_ln(stderr, _("Preparing worktree (new branch '%s')"), new_branch);
 		else
-			printf_ln(_("Preparing worktree (resetting branch '%s'; was at %s)"),
+			fprintf_ln(stderr, _("Preparing worktree (resetting branch '%s'; was at %s)"),
 				  new_branch,
 				  find_unique_abbrev(&commit->object.oid, DEFAULT_ABBREV));
 	} else if (new_branch) {
-		printf_ln(_("Preparing worktree (new branch '%s')"), new_branch);
+		fprintf_ln(stderr, _("Preparing worktree (new branch '%s')"), new_branch);
 	} else {
 		struct strbuf s = STRBUF_INIT;
 		if (!detach && !strbuf_check_branch_ref(&s, branch) &&
 		    ref_exists(s.buf))
-			printf_ln(_("Preparing worktree (checking out '%s')"),
+			fprintf_ln(stderr, _("Preparing worktree (checking out '%s')"),
 				  branch);
 		else {
 			struct commit *commit = lookup_commit_reference_by_name(branch);
 			if (!commit)
 				die(_("invalid reference: %s"), branch);
-			printf_ln(_("Preparing worktree (detached HEAD %s)"),
+			fprintf_ln(stderr, _("Preparing worktree (detached HEAD %s)"),
 				  find_unique_abbrev(&commit->object.oid, DEFAULT_ABBREV));
 		}
 		strbuf_release(&s);
@@ -1006,7 +1006,7 @@  static int remove_worktree(int ac, const char **av, const char *prefix)
 static void report_repair(int iserr, const char *path, const char *msg, void *cb_data)
 {
 	if (!iserr) {
-		printf_ln(_("repair: %s: %s"), msg, path);
+		fprintf_ln(stderr, _("repair: %s: %s"), msg, path);
 	} else {
 		int *exit_status = (int *)cb_data;
 		fprintf_ln(stderr, _("error: %s: %s"), msg, path);
diff --git a/t/t2401-worktree-prune.sh b/t/t2401-worktree-prune.sh
index a615d3b483..3d28c7f06b 100755
--- a/t/t2401-worktree-prune.sh
+++ b/t/t2401-worktree-prune.sh
@@ -19,7 +19,7 @@  test_expect_success 'worktree prune on normal repo' '
 test_expect_success 'prune files inside $GIT_DIR/worktrees' '
 	mkdir .git/worktrees &&
 	: >.git/worktrees/abc &&
-	git worktree prune --verbose >actual &&
+	git worktree prune --verbose 2>actual &&
 	cat >expect <<EOF &&
 Removing worktrees/abc: not a valid directory
 EOF
@@ -34,7 +34,7 @@  test_expect_success 'prune directories without gitdir' '
 	cat >expect <<EOF &&
 Removing worktrees/def: gitdir file does not exist
 EOF
-	git worktree prune --verbose >actual &&
+	git worktree prune --verbose 2>actual &&
 	test_cmp expect actual &&
 	! test -d .git/worktrees/def &&
 	! test -d .git/worktrees
@@ -45,7 +45,7 @@  test_expect_success SANITY 'prune directories with unreadable gitdir' '
 	: >.git/worktrees/def/def &&
 	: >.git/worktrees/def/gitdir &&
 	chmod u-r .git/worktrees/def/gitdir &&
-	git worktree prune --verbose >actual &&
+	git worktree prune --verbose 2>actual &&
 	test_i18ngrep "Removing worktrees/def: unable to read gitdir file" actual &&
 	! test -d .git/worktrees/def &&
 	! test -d .git/worktrees
@@ -55,7 +55,7 @@  test_expect_success 'prune directories with invalid gitdir' '
 	mkdir -p .git/worktrees/def/abc &&
 	: >.git/worktrees/def/def &&
 	: >.git/worktrees/def/gitdir &&
-	git worktree prune --verbose >actual &&
+	git worktree prune --verbose 2>actual &&
 	test_i18ngrep "Removing worktrees/def: invalid gitdir file" actual &&
 	! test -d .git/worktrees/def &&
 	! test -d .git/worktrees
@@ -65,7 +65,7 @@  test_expect_success 'prune directories with gitdir pointing to nowhere' '
 	mkdir -p .git/worktrees/def/abc &&
 	: >.git/worktrees/def/def &&
 	echo "$(pwd)"/nowhere >.git/worktrees/def/gitdir &&
-	git worktree prune --verbose >actual &&
+	git worktree prune --verbose 2>actual &&
 	test_i18ngrep "Removing worktrees/def: gitdir file points to non-existent location" actual &&
 	! test -d .git/worktrees/def &&
 	! test -d .git/worktrees
@@ -101,7 +101,7 @@  test_expect_success 'prune duplicate (linked/linked)' '
 	git worktree add --detach w2 &&
 	sed "s/w2/w1/" .git/worktrees/w2/gitdir >.git/worktrees/w2/gitdir.new &&
 	mv .git/worktrees/w2/gitdir.new .git/worktrees/w2/gitdir &&
-	git worktree prune --verbose >actual &&
+	git worktree prune --verbose 2>actual &&
 	test_i18ngrep "duplicate entry" actual &&
 	test -d .git/worktrees/w1 &&
 	! test -d .git/worktrees/w2
@@ -114,7 +114,7 @@  test_expect_success 'prune duplicate (main/linked)' '
 	git -C repo worktree add --detach ../wt &&
 	rm -fr wt &&
 	mv repo wt &&
-	git -C wt worktree prune --verbose >actual &&
+	git -C wt worktree prune --verbose 2>actual &&
 	test_i18ngrep "duplicate entry" actual &&
 	! test -d .git/worktrees/wt
 '
diff --git a/t/t2402-worktree-list.sh b/t/t2402-worktree-list.sh
index 4012bd67b0..c8a5a0aac6 100755
--- a/t/t2402-worktree-list.sh
+++ b/t/t2402-worktree-list.sh
@@ -134,7 +134,7 @@  test_expect_success '"list" all worktrees with prunable consistent with "prune"'
 	git worktree list >out &&
 	grep "/prunable  *[0-9a-f].* prunable$" out &&
 	! grep "/unprunable  *[0-9a-f].* unprunable$" out &&
-	git worktree prune --verbose >out &&
+	git worktree prune --verbose 2>out &&
 	test_i18ngrep "^Removing worktrees/prunable" out &&
 	test_i18ngrep ! "^Removing worktrees/unprunable" out
 '
diff --git a/t/t2406-worktree-repair.sh b/t/t2406-worktree-repair.sh
index f73741886b..5c44453e1c 100755
--- a/t/t2406-worktree-repair.sh
+++ b/t/t2406-worktree-repair.sh
@@ -45,9 +45,8 @@  test_corrupt_gitfile () {
 	git worktree add --detach corrupt &&
 	git -C corrupt rev-parse --absolute-git-dir >expect &&
 	eval "$butcher" &&
-	git -C "$repairdir" worktree repair >out 2>err &&
-	test_i18ngrep "$problem" out &&
-	test_must_be_empty err &&
+	git -C "$repairdir" worktree repair 2>err &&
+	test_i18ngrep "$problem" err &&
 	git -C corrupt rev-parse --absolute-git-dir >actual &&
 	test_cmp expect actual
 }
@@ -130,10 +129,9 @@  test_expect_success 'repair broken gitdir' '
 	sed s,orig/\.git$,moved/.git, .git/worktrees/orig/gitdir >expect &&
 	rm .git/worktrees/orig/gitdir &&
 	mv orig moved &&
-	git worktree repair moved >out 2>err &&
+	git worktree repair moved 2>err &&
 	test_cmp expect .git/worktrees/orig/gitdir &&
-	test_i18ngrep "gitdir unreadable" out &&
-	test_must_be_empty err
+	test_i18ngrep "gitdir unreadable" err
 '
 
 test_expect_success 'repair incorrect gitdir' '
@@ -141,10 +139,9 @@  test_expect_success 'repair incorrect gitdir' '
 	git worktree add --detach orig &&
 	sed s,orig/\.git$,moved/.git, .git/worktrees/orig/gitdir >expect &&
 	mv orig moved &&
-	git worktree repair moved >out 2>err &&
+	git worktree repair moved 2>err &&
 	test_cmp expect .git/worktrees/orig/gitdir &&
-	test_i18ngrep "gitdir incorrect" out &&
-	test_must_be_empty err
+	test_i18ngrep "gitdir incorrect" err
 '
 
 test_expect_success 'repair gitdir (implicit) from linked worktree' '
@@ -152,10 +149,9 @@  test_expect_success 'repair gitdir (implicit) from linked worktree' '
 	git worktree add --detach orig &&
 	sed s,orig/\.git$,moved/.git, .git/worktrees/orig/gitdir >expect &&
 	mv orig moved &&
-	git -C moved worktree repair >out 2>err &&
+	git -C moved worktree repair 2>err &&
 	test_cmp expect .git/worktrees/orig/gitdir &&
-	test_i18ngrep "gitdir incorrect" out &&
-	test_must_be_empty err
+	test_i18ngrep "gitdir incorrect" err
 '
 
 test_expect_success 'unable to repair gitdir (implicit) from main worktree' '
@@ -163,9 +159,8 @@  test_expect_success 'unable to repair gitdir (implicit) from main worktree' '
 	git worktree add --detach orig &&
 	cat .git/worktrees/orig/gitdir >expect &&
 	mv orig moved &&
-	git worktree repair >out 2>err &&
+	git worktree repair 2>err &&
 	test_cmp expect .git/worktrees/orig/gitdir &&
-	test_must_be_empty out &&
 	test_must_be_empty err
 '
 
@@ -178,12 +173,11 @@  test_expect_success 'repair multiple gitdir files' '
 	sed s,orig2/\.git$,moved2/.git, .git/worktrees/orig2/gitdir >expect2 &&
 	mv orig1 moved1 &&
 	mv orig2 moved2 &&
-	git worktree repair moved1 moved2 >out 2>err &&
+	git worktree repair moved1 moved2 2>err &&
 	test_cmp expect1 .git/worktrees/orig1/gitdir &&
 	test_cmp expect2 .git/worktrees/orig2/gitdir &&
-	test_i18ngrep "gitdir incorrect:.*orig1/gitdir$" out &&
-	test_i18ngrep "gitdir incorrect:.*orig2/gitdir$" out &&
-	test_must_be_empty err
+	test_i18ngrep "gitdir incorrect:.*orig1/gitdir$" err &&
+	test_i18ngrep "gitdir incorrect:.*orig2/gitdir$" err
 '
 
 test_expect_success 'repair moved main and linked worktrees' '