diff mbox series

chainlint: colorize problem annotations and test delimiters

Message ID pull.1324.git.git.1663023888412.gitgitgadget@gmail.com (mailing list archive)
State Superseded
Headers show
Series chainlint: colorize problem annotations and test delimiters | expand

Commit Message

Eric Sunshine Sept. 12, 2022, 11:04 p.m. UTC
From: Eric Sunshine <sunshine@sunshineco.com>

When `chainlint.pl` detects problems in a test definition, it emits the
test definition with "?!FOO?!" annotations highlighting the problems it
discovered. For instance, given this problematic test:

    test_expect_success 'discombobulate frobnitz' '
        git frob babble &&
        (echo balderdash; echo gnabgib) >expect &&
        for i in three two one
        do
            git nitfol $i
        done >actual
        test_cmp expect actual
    '

chainlint.pl will output:

    # chainlint: t1234-confusing.sh
    # chainlint: discombobulate frobnitz
    git frob babble &&
    (echo balderdash ; ?!AMP?! echo gnabgib) >expect &&
    for i in three two one
    do
    git nitfol $i ?!LOOP?!
    done >actual ?!AMP?!
    test_cmp expect actual

in which it may be difficult to spot the "?!FOO?!" annotations. The
problem is compounded when multiple tests, possibly in multiple
scripts, fail "linting", in which case it may be difficult to spot the
"# chainlint:" lines which delimit one problematic test from another.

To ameliorate this potential problem, colorize the "?!FOO?!" annotations
in order to quickly draw the test author's attention to the problem
spots, and colorize the "# chainlint:" lines to help the author identify
the name of each script and each problematic test.

Colorization is disabled automatically if output is not directed to a
terminal or if NO_COLOR environment variable is set. The implementation
is specific to Unix (it employs `tput` if available) but works equally
well in the Git for Windows development environment which emulates Unix
sufficiently.

Signed-off-by: Eric Sunshine <sunshine@sunshineco.com>
---
    chainlint: colorize problem annotations and test delimiters
    
    Peff nerd-sniped me yet again[1,2,3,4].
    
    This is atop "es/chainlint" (eab3357b05b2) in "next".
    
    [1]
    https://lore.kernel.org/git/YJzGcZpZ+E9R0gYd@coredump.intra.peff.net/
    [2]
    https://lore.kernel.org/git/Yx1x5lme2SGBjfia@coredump.intra.peff.net/
    [3]
    https://lore.kernel.org/git/CAPig+cRJVn-mbA6-jOmNfDJtK_nX4ZTw+OcNShvvz8zcQYbCHQ@mail.gmail.com/
    [4]
    https://lore.kernel.org/git/Yx4pg2t6JXR+lsd4@coredump.intra.peff.net/

Published-As: https://github.com/gitgitgadget/git/releases/tag/pr-git-1324%2Fsunshineco%2Fchainlintcolor-v1
Fetch-It-Via: git fetch https://github.com/gitgitgadget/git pr-git-1324/sunshineco/chainlintcolor-v1
Pull-Request: https://github.com/git/git/pull/1324

 t/chainlint.pl | 44 +++++++++++++++++++++++++++++++++++++++++---
 1 file changed, 41 insertions(+), 3 deletions(-)


base-commit: 50f0e44ec40b5fab5d618dd26ebd776c47e9af13

Comments

Junio C Hamano Sept. 12, 2022, 11:55 p.m. UTC | #1
"Eric Sunshine via GitGitGadget" <gitgitgadget@gmail.com> writes:

> +	$checked =~ s/(\?![^?]+\?!)/$c->{bold}$c->{red}$1$c->{reset}/mg;

It may be just me, but coloring the whole "?!LOOP?!" in red feels a
bit strange.  I would have expected more like

	if ($c->{color_in_use}) {
		$checked =~ s/\?!([^?]+)\?!/$c->{bold}$c->{red}$1$c->{reset}/mg;
	}

IOW, switching between "?!LOOP?!" and "<BOLD><RED>LOOP<RESET>".

But it may be just me.

> +# Restore TERM if test framework set it to "dumb" so 'tput' will work; do this
> +# outside of get_colors() since under 'ithreads' all threads use %ENV of main
> +# thread and ignore %ENV changes in subthreads.
> +$ENV{TERM} = $ENV{USER_TERM} if $ENV{USER_TERM};

Sounds quite sensible.
Eric Sunshine Sept. 13, 2022, 12:14 a.m. UTC | #2
On Mon, Sep 12, 2022 at 7:55 PM Junio C Hamano <gitster@pobox.com> wrote:
> "Eric Sunshine via GitGitGadget" <gitgitgadget@gmail.com> writes:
> > +     $checked =~ s/(\?![^?]+\?!)/$c->{bold}$c->{red}$1$c->{reset}/mg;
>
> It may be just me, but coloring the whole "?!LOOP?!" in red feels a
> bit strange.  I would have expected more like
>
>         if ($c->{color_in_use}) {
>                 $checked =~ s/\?!([^?]+)\?!/$c->{bold}$c->{red}$1$c->{reset}/mg;
>         }
>
> IOW, switching between "?!LOOP?!" and "<BOLD><RED>LOOP<RESET>".
>
> But it may be just me.

That's possible, but I'd rather not do that for a couple reasons:

(1) Even with the coloring, I still find it handy to be able to search
for "?!" in the output in order to jump to the next problem (or to
filter to just the problem lines via, say, grep).

(2) In practice, I found that even after coloring those annotations in
red, it was still easy for the eye to glide right over them in the
output without really noticing them. Switching it to bold red helped a
bit, but my eye still glided over them sometimes. One possible reason
that the eye was able to glide over them may be because the "?!FOO?!"
annotations are very short bits of text buried in the much larger and
textually noisy test body. As such, having more characters "?!...?!"
may help capture the eye more easily than fewer characters. (In fact,
I briefly considered coloring the entire line red to combat the
eye-gliding problem but wasn't sure if that would be helpful or
hurtful.)
Jeff King Sept. 13, 2022, 12:15 a.m. UTC | #3
On Mon, Sep 12, 2022 at 11:04:48PM +0000, Eric Sunshine via GitGitGadget wrote:

> @@ -585,12 +585,14 @@ sub check_test {
>  	my $parser = TestParser->new(\$body);
>  	my @tokens = $parser->parse();
>  	return unless $emit_all || grep(/\?![^?]+\?!/, @tokens);
> +	my $c = main::fd_colors(1);
>  	my $checked = join(' ', @tokens);
>  	$checked =~ s/^\n//;
>  	$checked =~ s/^ //mg;
>  	$checked =~ s/ $//mg;
> +	$checked =~ s/(\?![^?]+\?!)/$c->{bold}$c->{red}$1$c->{reset}/mg;
>  	$checked .= "\n" unless $checked =~ /\n$/;
> -	push(@{$self->{output}}, "# chainlint: $title\n$checked");
> +	push(@{$self->{output}}, "$c->{blue}# chainlint: $title$c->{reset}\n$checked");
>  }

Nice, this ended up much simpler than I feared. I thought we'd have to
touch each spot that added an annotation, and then deal with the
internal text matching (like the one in the hunk above). Being able to
do it centrally on output is much nicer.

> +my @NOCOLORS = (bold => '', reset => '', blue => '', green => '', red => '');
> +my %COLORS = ();
> +sub get_colors {
> +	return \%COLORS if %COLORS;
> +	if (exists($ENV{NO_COLOR}) ||
> +	    system("tput sgr0 >/dev/null 2>&1") != 0 ||
> +	    system("tput bold >/dev/null 2>&1") != 0 ||
> +	    system("tput setaf 1 >/dev/null 2>&1") != 0) {
> +		%COLORS = @NOCOLORS;
> +		return \%COLORS;
> +	}
> +	%COLORS = (bold  => `tput bold`,
> +		   reset => `tput sgr0`,
> +		   blue  => `tput setaf 4`,
> +		   green => `tput setaf 2`,
> +		   red   => `tput setaf 1`);
> +	chomp(%COLORS);
> +	return \%COLORS;
> +}

This is a lot of new processes. Should be OK in the run-once-for-all-tests
mode. It does make me wonder how much time regular test-lib.sh spends
doing these tput checks for every script (at least it's not every
snippet!).

It feels like we could build a color.sh snippet once and then include it
in each script. But maybe that is dumb, since you could in theory build
in one terminal and then run in another. Unlikely, but it shows that
file dependencies are a mismatch. I guess a better match would be
stuffing it into the environment before starting all of the tests.

> [...]

I ran this on my pre-fixup state where I had a half-dozen linter checks.
It's _so_ much more readable. Thanks for working on it.

-Peff
Jeff King Sept. 13, 2022, 12:16 a.m. UTC | #4
On Mon, Sep 12, 2022 at 04:55:01PM -0700, Junio C Hamano wrote:

> "Eric Sunshine via GitGitGadget" <gitgitgadget@gmail.com> writes:
> 
> > +	$checked =~ s/(\?![^?]+\?!)/$c->{bold}$c->{red}$1$c->{reset}/mg;
> 
> It may be just me, but coloring the whole "?!LOOP?!" in red feels a
> bit strange.  I would have expected more like
> 
> 	if ($c->{color_in_use}) {
> 		$checked =~ s/\?!([^?]+)\?!/$c->{bold}$c->{red}$1$c->{reset}/mg;
> 	}
> 
> IOW, switching between "?!LOOP?!" and "<BOLD><RED>LOOP<RESET>".
> 
> But it may be just me.

Having seen the output in the wild (or at least on the example which I
found hard to read originally), I kind of like the "?!" being retained
even in the color version. It really makes things stand out.

-Peff
Junio C Hamano Sept. 13, 2022, 12:21 a.m. UTC | #5
Eric Sunshine <sunshine@sunshineco.com> writes:

> (2) In practice, I found that even after coloring those annotations in
> red, it was still easy for the eye to glide right over them in the
> output without really noticing them. Switching it to bold red helped a
> bit, but my eye still glided over them sometimes. One possible reason
> that the eye was able to glide over them may be because the "?!FOO?!"
> annotations are very short bits of text buried in the much larger and
> textually noisy test body.

Maybe partly because I work with black-ink-on-white-paper terminal
setting, and maybe partly because my color perception is suboptimal,
I learned to use "[diff.color] old = red reverse", because non-bold
red letters do not stand out enough.  Perhaps you may want to try
reverse output to see how well it makes them stand out for you.

I do not think if configurability like "git diff" has is necessary;
it would be overkill.  I personally do not mind more noise "?!"
around the keyword, especially since these are only shown when there
are problems detected.
Eric Sunshine Sept. 13, 2022, 12:30 a.m. UTC | #6
On Mon, Sep 12, 2022 at 8:15 PM Jeff King <peff@peff.net> wrote:
> On Mon, Sep 12, 2022 at 11:04:48PM +0000, Eric Sunshine via GitGitGadget wrote:
> > +my @NOCOLORS = (bold => '', reset => '', blue => '', green => '', red => '');
> > +my %COLORS = ();
> > +sub get_colors {
> > +     return \%COLORS if %COLORS;
> > +     if (exists($ENV{NO_COLOR}) ||
> > +         system("tput sgr0 >/dev/null 2>&1") != 0 ||
> > +         system("tput bold >/dev/null 2>&1") != 0 ||
> > +         system("tput setaf 1 >/dev/null 2>&1") != 0) {
> > +             %COLORS = @NOCOLORS;
> > +             return \%COLORS;
> > +     }
> > +     %COLORS = (bold  => `tput bold`,
> > +                reset => `tput sgr0`,
> > +                blue  => `tput setaf 4`,
> > +                green => `tput setaf 2`,
> > +                red   => `tput setaf 1`);
> > +     chomp(%COLORS);
> > +     return \%COLORS;
> > +}
>
> This is a lot of new processes. Should be OK in the run-once-for-all-tests
> mode. It does make me wonder how much time regular test-lib.sh spends
> doing these tput checks for every script (at least it's not every
> snippet!).

This is indeed a lot of new processes, but this color interrogation is
done lazily, only if a problem is detected, so it should be zero-cost
in the (hopefully) normal case of a lint-clean script.

I had the exact same thought about the cost being paid by test-lib.sh
making all those `tput` invocations.

> It feels like we could build a color.sh snippet once and then include it
> in each script. But maybe that is dumb, since you could in theory build
> in one terminal and then run in another. Unlikely, but it shows that
> file dependencies are a mismatch. I guess a better match would be
> stuffing it into the environment before starting all of the tests.

That might be worth considering at some point.

> I ran this on my pre-fixup state where I had a half-dozen linter checks.
> It's _so_ much more readable. Thanks for working on it.

Good to hear.
Jeff King Sept. 13, 2022, 12:32 a.m. UTC | #7
On Mon, Sep 12, 2022 at 08:15:33PM -0400, Jeff King wrote:

> This is a lot of new processes. Should be OK in the run-once-for-all-tests
> mode. It does make me wonder how much time regular test-lib.sh spends
> doing these tput checks for every script (at least it's not every
> snippet!).
> 
> It feels like we could build a color.sh snippet once and then include it
> in each script. But maybe that is dumb, since you could in theory build
> in one terminal and then run in another. Unlikely, but it shows that
> file dependencies are a mismatch. I guess a better match would be
> stuffing it into the environment before starting all of the tests.

I timed running the suite with and without TERM=dumb, as that is enough
to get test-lib.sh to skip running tput entirely. It doesn't seem to
make a measurable difference for me. Possibly it could on Windows, but I
don't think it's worth worrying about too much.

(If we did want to worry, "tput -S" is another option; it's not in
POSIX, but probably could be used on Windows).

And of course this was all "gee, I wonder about test-lib.sh"; it is all
orthogonal to your patch.

-Peff
Eric Sunshine Sept. 13, 2022, 12:39 a.m. UTC | #8
On Mon, Sep 12, 2022 at 8:21 PM Junio C Hamano <gitster@pobox.com> wrote:
> Eric Sunshine <sunshine@sunshineco.com> writes:
> > (2) In practice, I found that even after coloring those annotations in
> > red, it was still easy for the eye to glide right over them in the
> > output without really noticing them. Switching it to bold red helped a
> > bit, but my eye still glided over them sometimes. One possible reason
> > that the eye was able to glide over them may be because the "?!FOO?!"
> > annotations are very short bits of text buried in the much larger and
> > textually noisy test body.
>
> Maybe partly because I work with black-ink-on-white-paper terminal
> setting, and maybe partly because my color perception is suboptimal,
> I learned to use "[diff.color] old = red reverse", because non-bold
> red letters do not stand out enough.  Perhaps you may want to try
> reverse output to see how well it makes them stand out for you.

Hmm, yes, that might be worth investigating. I also typically work
with black-ink-on-white-paper terminal, and although the problem is
perhaps worse with that color scheme, I nevertheless found that my eye
would sometimes glide over the red annotations even when I tested with
other color schemes (i.e. light-ink-on-dark-paper).
Jeff King Sept. 13, 2022, 1:34 a.m. UTC | #9
On Mon, Sep 12, 2022 at 08:30:02PM -0400, Eric Sunshine wrote:

> This is indeed a lot of new processes, but this color interrogation is
> done lazily, only if a problem is detected, so it should be zero-cost
> in the (hopefully) normal case of a lint-clean script.
> 
> I had the exact same thought about the cost being paid by test-lib.sh
> making all those `tput` invocations.

Ah, right, that's even better.

I wondered if we could use the same trick in test-lib.sh, but it does
color some output even on success. But on further thought, the reason
that I couldn't measure any impact of tput in my other message may have
just been because I was running under "prove". So there's no tty and
thus no coloring in the first place. Not to mention that I am using
--verbose-log, which also suppresses color.

So I suspect there is really nothing to speed up at all. Most cases
running all of the tests will end up turning off color anyway. And if
they are not, they are probably bottle-necked on the terminal speed. ;)

-Peff
diff mbox series

Patch

diff --git a/t/chainlint.pl b/t/chainlint.pl
index 386999ce65d..3a6d85ecfdd 100755
--- a/t/chainlint.pl
+++ b/t/chainlint.pl
@@ -585,12 +585,14 @@  sub check_test {
 	my $parser = TestParser->new(\$body);
 	my @tokens = $parser->parse();
 	return unless $emit_all || grep(/\?![^?]+\?!/, @tokens);
+	my $c = main::fd_colors(1);
 	my $checked = join(' ', @tokens);
 	$checked =~ s/^\n//;
 	$checked =~ s/^ //mg;
 	$checked =~ s/ $//mg;
+	$checked =~ s/(\?![^?]+\?!)/$c->{bold}$c->{red}$1$c->{reset}/mg;
 	$checked .= "\n" unless $checked =~ /\n$/;
-	push(@{$self->{output}}, "# chainlint: $title\n$checked");
+	push(@{$self->{output}}, "$c->{blue}# chainlint: $title$c->{reset}\n$checked");
 }
 
 sub parse_cmd {
@@ -615,6 +617,39 @@  if (eval {require Time::HiRes; Time::HiRes->import(); 1;}) {
 	$interval = sub { return Time::HiRes::tv_interval(shift); };
 }
 
+# Restore TERM if test framework set it to "dumb" so 'tput' will work; do this
+# outside of get_colors() since under 'ithreads' all threads use %ENV of main
+# thread and ignore %ENV changes in subthreads.
+$ENV{TERM} = $ENV{USER_TERM} if $ENV{USER_TERM};
+
+my @NOCOLORS = (bold => '', reset => '', blue => '', green => '', red => '');
+my %COLORS = ();
+sub get_colors {
+	return \%COLORS if %COLORS;
+	if (exists($ENV{NO_COLOR}) ||
+	    system("tput sgr0 >/dev/null 2>&1") != 0 ||
+	    system("tput bold >/dev/null 2>&1") != 0 ||
+	    system("tput setaf 1 >/dev/null 2>&1") != 0) {
+		%COLORS = @NOCOLORS;
+		return \%COLORS;
+	}
+	%COLORS = (bold  => `tput bold`,
+		   reset => `tput sgr0`,
+		   blue  => `tput setaf 4`,
+		   green => `tput setaf 2`,
+		   red   => `tput setaf 1`);
+	chomp(%COLORS);
+	return \%COLORS;
+}
+
+my %FD_COLORS = ();
+sub fd_colors {
+	my $fd = shift;
+	return $FD_COLORS{$fd} if exists($FD_COLORS{$fd});
+	$FD_COLORS{$fd} = -t $fd ? get_colors() : {@NOCOLORS};
+	return $FD_COLORS{$fd};
+}
+
 sub ncores {
 	# Windows
 	return $ENV{NUMBER_OF_PROCESSORS} if exists($ENV{NUMBER_OF_PROCESSORS});
@@ -630,6 +665,8 @@  sub show_stats {
 	my $walltime = $interval->($start_time);
 	my ($usertime) = times();
 	my ($total_workers, $total_scripts, $total_tests, $total_errs) = (0, 0, 0, 0);
+	my $c = fd_colors(2);
+	print(STDERR $c->{green});
 	for (@$stats) {
 		my ($worker, $nscripts, $ntests, $nerrs) = @$_;
 		print(STDERR "worker $worker: $nscripts scripts, $ntests tests, $nerrs errors\n");
@@ -638,7 +675,7 @@  sub show_stats {
 		$total_tests += $ntests;
 		$total_errs += $nerrs;
 	}
-	printf(STDERR "total: %d workers, %d scripts, %d tests, %d errors, %.2fs/%.2fs (wall/user)\n", $total_workers, $total_scripts, $total_tests, $total_errs, $walltime, $usertime);
+	printf(STDERR "total: %d workers, %d scripts, %d tests, %d errors, %.2fs/%.2fs (wall/user)$c->{reset}\n", $total_workers, $total_scripts, $total_tests, $total_errs, $walltime, $usertime);
 }
 
 sub check_script {
@@ -656,8 +693,9 @@  sub check_script {
 		my $parser = ScriptParser->new(\$s);
 		1 while $parser->parse_cmd();
 		if (@{$parser->{output}}) {
+			my $c = fd_colors(1);
 			my $s = join('', @{$parser->{output}});
-			$emit->("# chainlint: $path\n" . $s);
+			$emit->("$c->{bold}$c->{blue}# chainlint: $path$c->{reset}\n" . $s);
 			$nerrs += () = $s =~ /\?![^?]+\?!/g;
 		}
 		$ntests += $parser->{ntests};