git@vger.kernel.org mailing list mirror (one of many)
 help / color / mirror / code / Atom feed
From: Jeff King <peff@peff.net>
To: gennady.kupava@gmail.com
Cc: git@vger.kernel.org, Gennady Kupava <gkupava@bloomberg.net>
Subject: Re: [PATCH] Reduce performance penalty for turned off traces
Date: Sun, 12 Nov 2017 14:17:38 +0000	[thread overview]
Message-ID: <20171112141737.nmnsygm4wrhtkqwb@sigill.intra.peff.net> (raw)
In-Reply-To: <20171111192858.27255-1-gennady.kupava@gmail.com>

On Sat, Nov 11, 2017 at 07:28:58PM +0000, gennady.kupava@gmail.com wrote:

> From: Gennady Kupava <gkupava@bloomberg.net>
> 
> Signed-off-by: Gennady Kupava <gkupava@bloomberg.net>

Thanks, and welcome to the list.

> ---
> One of the tasks siggested in scope of 'Git sprint weekend'.
> Couple of chioces made here:

These kinds of choices/caveats (along with the motivation for the patch)
should go into the commit message so people running "git log" later can
see them.

>  1. Use constant instead of NULL to indicate default trace level, this just
> makes everything simpler.

I think this makes sense, as we were translating NULL into this default
struct behind the scenes already. As we discussed off-list, this does
mean that you can no longer do:

  trace_printf_key(NULL, "foo");

to send to the default key, and instead must do:

  trace_printf("foo");

The second one has always been the preferred way of spelling it, but the
first one happened to work. So the only fallout would be if somebody is
using the non-preferred method, they'd now segfault. There aren't any
such calls in the current code base, though, and I find it rather
unlikely that there would be new instances in topics other people are
working on.

I think it may be worth splitting that out into a separate preparatory
patch to make it more clear what's going on (especially if our
assumption turns out wrong and somebody does end up tracing a problem
back to it).

>  2. Move just enough from implementation to header, to be able to do check
> before calling actual functions.

Makes sense.

>  3. Most controversail: do not support optimization for older
>     compilers not supporting variadic templates in macroses. Problem
>     is that theoretically someone may write some complicated trace
>     while would work in 'modern' compiler and be too slow in more
>     'classic' compilers, however expectation is that risk of that is
>     quite low and 'classic' compilers will go away eventually.

I think this is probably acceptable. I know we've discussed elsewhere
recently how common such compilers actually are, and whether we could
give up on them altogether.

If we wanted to, we could support that case by using inline functions in
the header (though it does make me wonder if compilers that old also do
not actually end up inlining).

I did manually disable HAVE_VARIADIC_MACROS and confirmed that the
result builds and passes the test suite (though I suspect that GIT_TRACE
is not well exercised by the suite).

> diff --git a/trace.c b/trace.c
> index 7508aea02..180ee3b00 100644
> --- a/trace.c
> +++ b/trace.c
> @@ -25,26 +25,14 @@
>  #include "cache.h"
>  #include "quote.h"
>  
> -/*
> - * "Normalize" a key argument by converting NULL to our trace_default,
> - * and otherwise passing through the value. All caller-facing functions
> - * should normalize their inputs in this way, though most get it
> - * for free by calling get_trace_fd() (directly or indirectly).
> - */
> -static void normalize_trace_key(struct trace_key **key)
> -{
> -	static struct trace_key trace_default = { "GIT_TRACE" };
> -	if (!*key)
> -		*key = &trace_default;
> -}
> +struct trace_key trace_default_key = { TRACE_KEY_PREFIX, 0, 0, 0 };

Makes sense. We no longer auto-normalize, but just expect the
appropriate functions to pass a pointer to the default key themselves.

> +struct trace_key trace_perf_key = TRACE_KEY_INIT(PERFORMANCE);

This change was unexpected, but I think you just moved this up to keep
all the pre-declared structs together. Makes sense.

>  /* Get a trace file descriptor from "key" env variable. */
>  static int get_trace_fd(struct trace_key *key)
>  {
>  	const char *trace;
>  
> -	normalize_trace_key(&key);
> -
>  	/* don't open twice */
>  	if (key->initialized)
>  		return key->fd;

And this and similar changes to drop normalize_trace_key() all make
sense with the earlier hunk. Good.

> @@ -341,7 +324,7 @@ void trace_repo_setup(const char *prefix)
>  
>  int trace_want(struct trace_key *key)
>  {
> -	return !!get_trace_fd(key);
> +       return !!get_trace_fd(key);
>  }

This line accidentally swapped out the tab for spaces.

> diff --git a/trace.h b/trace.h
> index 179b249c5..64326573a 100644
> --- a/trace.h
> +++ b/trace.h
> @@ -4,6 +4,8 @@
>  #include "git-compat-util.h"
>  #include "strbuf.h"
>  
> +#define TRACE_KEY_PREFIX "GIT_TRACE"
> [..]
> -#define TRACE_KEY_INIT(name) { "GIT_TRACE_" #name, 0, 0, 0 }
> +#define TRACE_KEY_INIT(name) { TRACE_KEY_PREFIX "_" #name, 0, 0, 0 }

I see you pulled this out so you could use TRACE_KEY_PREFIX elsewhere
for the default key. Yes, the default key and the prefix do happen to be
related in that way, but I actually think it was a bit less obfuscated
the original way, even it repeated the string "GIT_TRACE" twice.

> +#define trace_pass(key) ((key)->fd || !(key)->initialized)

Factoring this out makes sense, since we have to repeat it in each
macro.

Speaking of macros, one side effect of this whole patch is that the
"key" parmaeter is going to be evaluated multiple times. I think that's
an acceptable tradeoff, as we'd basically always expect to pass the
address of a static struct here.

If that's a problem I think we _could_ do it with a combination of
macros and inline functions. The macro has to go in the outer layer in
order to set __LINE__ properly. But something like:

  static inline
  void trace_printf_key_helper(const char *context, int line,
                               struct trace_key *key,
			       const char *fmt, ...)
  {
	if (trace_pass(key)) {
		va_list ap;
		va_start(ap, fmt);
		trace_vprintf_key_fl(context, line, key, fmt, ap);
		va_end(ap);
	}
  }

  #define trace_printf_key(key, ...) \
	trace_printf_key_helper(TRACE_CONTEXT, __LINE__, key, __VA_ARGS__);

would work, I think.

> +#define trace_printf(...)						    \
> +	do {								    \
> +		if (trace_pass(&trace_default_key))			    \
> +			trace_printf_key_fl(TRACE_CONTEXT, __LINE__,        \
> +					    &trace_default_key,__VA_ARGS__);\
> +	} while(0)
> +
> +#define trace_printf_key(key, ...)					    \
> +	do {								    \
> +		if (trace_pass(key))					    \
> +			trace_printf_key_fl(TRACE_CONTEXT, __LINE__, key,   \
> +					    __VA_ARGS__);		    \
> +	} while(0)

Now that these definitions are getting a bit more complex, I wonder if
we can implement them in terms of each other. I.e., could the first one
be:

  #define trace_printf(...) trace_printf_key(&trace_default_key, __VA_ARGS__)

I'm not sure if there are any gotchas with recursive variadic macros. If
it's just this one macro that's not too big a deal, and it looks like
most of the rest of them end up having to call different functions and
can't nest like this. So it may not be worth troubling about.

> +#define trace_argv_printf(argv, ...)					    \
> [...]

The rest of this looks good.

I tried timing a simple loop like:

diff --git a/git.c b/git.c
index 9e96dd4090..f3dbc15a99 100644
--- a/git.c
+++ b/git.c
@@ -626,6 +626,11 @@ int cmd_main(int argc, const char **argv)
 {
 	const char *cmd;
 	int done_help = 0;
+	int i;
+
+	for (i = 0; i < 1000000; i++)
+		trace_printf("item %d", i);
+	return 0;
 
 	cmd = argv[0];
 	if (!cmd)

Without your patch, the times for GIT_TRACE=1 and GIT_TRACE=0 are about
500ms and 9ms respectively.

After your patch, the GIT_TRACE=1 time remains the same but GIT_TRACE=0
drops to 1ms.

So it is measurable, and we might expect that tracing a really big loop
(say over all of the objects in the repository) would benefit. OTOH, a
real loop would actually be doing other stuff, so the speedup would be
less dramatic. Still, it seems like an easy win.

-Peff

  reply	other threads:[~2017-11-12 14:17 UTC|newest]

Thread overview: 20+ messages / expand[flat|nested]  mbox.gz  Atom feed  top
2017-11-11 19:28 [PATCH] Reduce performance penalty for turned off traces gennady.kupava
2017-11-12 14:17 ` Jeff King [this message]
2017-11-12 23:24   ` Gennady Kupava
2017-11-17 22:12     ` Jeff King
2017-11-15 19:14   ` Stefan Beller
2017-11-17 22:16     ` Jeff King
2017-11-19  0:42       ` [PATCH 1/2] Simplify tracing code by removing trace key normalization concept gennady.kupava
2017-11-19  0:42         ` [PATCH 2/2] Reduce performance cost of the trace if trace category is disabled gennady.kupava
2017-11-19  8:27           ` Johannes Sixt
2017-11-19 13:18             ` Gennady Kupava
2017-11-19  2:19         ` [PATCH 1/2] Simplify tracing code by removing trace key normalization concept Junio C Hamano
2017-11-19 13:16           ` Gennady Kupava
2017-11-20  0:24             ` Junio C Hamano
2017-11-20  4:59               ` Junio C Hamano
2017-11-26 20:11                 ` [PATCH 1/2] trace: remove trace key normalization gennady.kupava
2017-11-26 20:11                   ` [PATCH 2/2] trace: improve performance while category is disabled gennady.kupava
2017-11-27  1:21                     ` Junio C Hamano
2017-11-27  1:32                       ` Junio C Hamano
2017-11-27  3:25                         ` Junio C Hamano
2017-11-27 10:12                           ` Gennady Kupava

Reply instructions:

You may reply publicly to this message via plain-text email
using any one of the following methods:

* Save the following mbox file, import it into your mail client,
  and reply-to-all from there: mbox

  Avoid top-posting and favor interleaved quoting:
  https://en.wikipedia.org/wiki/Posting_style#Interleaved_style

  List information: http://vger.kernel.org/majordomo-info.html

* Reply using the --to, --cc, and --in-reply-to
  switches of git-send-email(1):

  git send-email \
    --in-reply-to=20171112141737.nmnsygm4wrhtkqwb@sigill.intra.peff.net \
    --to=peff@peff.net \
    --cc=gennady.kupava@gmail.com \
    --cc=git@vger.kernel.org \
    --cc=gkupava@bloomberg.net \
    /path/to/YOUR_REPLY

  https://kernel.org/pub/software/scm/git/docs/git-send-email.html

* If your mail client supports setting the In-Reply-To header
  via mailto: links, try the mailto: link
Be sure your reply has a Subject: header at the top and a blank line before the message body.
Code repositories for project(s) associated with this public inbox

	https://80x24.org/mirrors/git.git

This is a public inbox, see mirroring instructions
for how to clone and mirror all data and code used for this inbox;
as well as URLs for read-only IMAP folder(s) and NNTP newsgroup(s).