threads / patch / 40245

patch, 2 partsclarify sideband muxing in GIT_TRACE_PACKET

Subject: [PATCH 0/2] clarify sideband muxing in GIT_TRACE_PACKET

## tl;dr

12 messages between Sep 1, 2015 and Sep 1, 2015. Diffs are folded; open one to read it.

replies: 11people: 3as markdown or json

Jeff King· Sep 1, 2015, 20:22 UTC · lore

I happened to be debugging push with GIT_TRACE_PACKET today, and got confused by the mixture of trace from the sideband demuxer and push itself (details in patch 2/2). This series fixes it by showing a distinct prefix for the sideband reads.

There's some trickery with start_async() involved, so I've tested it both with and without NO_PTHREADS set.

  [1/2]: run-command: provide in_async query function
  [2/2]: pkt-line: show packets in async processes as "sideband"
-Peff
Jeff King· Sep 1, 2015, 20:22 UTC · re: Jeff King · lore

[PATCH 1/2] run-command: provide in_async query function

It's not easy for arbitrary code to find out whether it is running in an async process or not. A top-level function which is fed to start_async() can know (you just pass down an argument saying "you are async"). But that function may call other global functions, and we would not want to have to pass the information all the way through the call stack.

Nor can we simply set a global variable, as those may be shared between async threads and the main thread (if the platform supports pthreads). We need pthread tricks _or_ a global variable, depending on how start_async is implemented.

The callers don't have enough information to do this right, so let's provide a simple query function that does. Fortunately we can reuse the existing infrastructure to make the pthread case simple (and even simplify die_async() by using our new function).

Signed-off-by: Jeff King <peff@peff.net>
---
 run-command.c | 16 +++++++++++++++-
 run-command.h |  1 +
 2 files changed, 16 insertions(+), 1 deletion(-)
Show changes to 2 files +16 −1

run-command.c, run-command.h

diff --git a/run-command.c b/run-command.c
index 3277cf7..c8029f2 100644
--- a/run-command.c
+++ b/run-command.c
@@ -595,7 +595,7 @@ static NORETURN void die_async(const char *err, va_list params)
 {
 	vreportf("fatal: ", err, params);
 
-	if (!pthread_equal(main_thread, pthread_self())) {
+	if (in_async()) {
 		struct async *async = pthread_getspecific(async_key);
 		if (async->proc_in >= 0)
 			close(async->proc_in);
@@ -614,6 +614,13 @@ static int async_die_is_recursing(void)
 	return ret != NULL;
 }
 
+int in_async(void)
+{
+	if (!main_thread_set)
+		return 0; /* no asyncs started yet */
+	return !pthread_equal(main_thread, pthread_self());
+}
+
 #else
 
 static struct {
@@ -653,6 +660,12 @@ int git_atexit(void (*handler)(void))
 }
 #define atexit git_atexit
 
+static int process_is_async;
+int in_async(void)
+{
+	return process_is_async;
+}
+
 #endif
 
 int start_async(struct async *async)
@@ -712,6 +725,7 @@ int start_async(struct async *async)
 		if (need_out)
 			close(fdout[0]);
 		git_atexit_clear();
+		process_is_async = 1;
 		exit(!!async->proc(proc_in, proc_out, async->data));
 	}
 
diff --git a/run-command.h b/run-command.h
index 5b4425a..629fab7 100644
--- a/run-command.h
+++ b/run-command.h
@@ -118,5 +118,6 @@ struct async {
 
 int start_async(struct async *async);
 int finish_async(struct async *async);
+int in_async(void);
 
 #endif
-- 
2.5.1.739.g7891f6b
Jeff King· Sep 1, 2015, 20:26 UTC · re: Jeff King · lore

Re: [PATCH 1/2] run-command: provide in_async query function

On Tue, Sep 01, 2015 at 04:22:43PM -0400, Jeff King wrote:
> diff --git a/run-command.c b/run-command.c
> index 3277cf7..c8029f2 100644
> --- a/run-command.c
> +++ b/run-command.c

This diff is a little funny to read because the interesting context is far away, and it is not immediately obvious why we are defining the function twice. This:

Show 21 quoted lines
> @@ -595,7 +595,7 @@ static NORETURN void die_async(const char *err, va_list params)
>  {
>  	vreportf("fatal: ", err, params);
>  
> -	if (!pthread_equal(main_thread, pthread_self())) {
> +	if (in_async()) {
>  		struct async *async = pthread_getspecific(async_key);
>  		if (async->proc_in >= 0)
>  			close(async->proc_in);
> @@ -614,6 +614,13 @@ static int async_die_is_recursing(void)
>  	return ret != NULL;
>  }
>  
> +int in_async(void)
> +{
> +	if (!main_thread_set)
> +		return 0; /* no asyncs started yet */
> +	return !pthread_equal(main_thread, pthread_self());
> +}
> +
>  #else
is all inside #ifndef NO_PTHREADS, and this:
Show 11 quoted lines
> @@ -653,6 +660,12 @@ int git_atexit(void (*handler)(void))
>  }
>  #define atexit git_atexit
>  
> +static int process_is_async;
> +int in_async(void)
> +{
> +	return process_is_async;
> +}
> +
>  #endif
is the "#else" case where we fork.
-Peff
Junio C Hamano· Sep 1, 2015, 22:09 UTC · re: Jeff King · lore

Re: [PATCH 1/2] run-command: provide in_async query function

Jeff King <peff@peff.net> writes:
Show 21 quoted lines
> It's not easy for arbitrary code to find out whether it is
> running in an async process or not. A top-level function
> which is fed to start_async() can know (you just pass down
> an argument saying "you are async"). But that function may
> call other global functions, and we would not want to have
> to pass the information all the way through the call stack.
>
> Nor can we simply set a global variable, as those may be
> shared between async threads and the main thread (if the
> platform supports pthreads). We need pthread tricks _or_ a
> global variable, depending on how start_async is
> implemented.
>
> The callers don't have enough information to do this right,
> so let's provide a simple query function that does.
> Fortunately we can reuse the existing infrastructure to make
> the pthread case simple (and even simplify die_async() by
> using our new function).
>
> Signed-off-by: Jeff King <peff@peff.net>
> ---

What is not immediately obvious from the above description is why a code may want to care if it is in_async() in the first place.

If there weren't the die_async() update, the readers might have been left utterly baffled (or they can somehow see this is related to 2/2) but it is a bit hard to arrange in "git log" as going to child is harder.

The patch looks good.  Thanks.
Show 63 quoted lines
>  run-command.c | 16 +++++++++++++++-
>  run-command.h |  1 +
>  2 files changed, 16 insertions(+), 1 deletion(-)
>
> diff --git a/run-command.c b/run-command.c
> index 3277cf7..c8029f2 100644
> --- a/run-command.c
> +++ b/run-command.c
> @@ -595,7 +595,7 @@ static NORETURN void die_async(const char *err, va_list params)
>  {
>  	vreportf("fatal: ", err, params);
>  
> -	if (!pthread_equal(main_thread, pthread_self())) {
> +	if (in_async()) {
>  		struct async *async = pthread_getspecific(async_key);
>  		if (async->proc_in >= 0)
>  			close(async->proc_in);
> @@ -614,6 +614,13 @@ static int async_die_is_recursing(void)
>  	return ret != NULL;
>  }
>  
> +int in_async(void)
> +{
> +	if (!main_thread_set)
> +		return 0; /* no asyncs started yet */
> +	return !pthread_equal(main_thread, pthread_self());
> +}
> +
>  #else
>  
>  static struct {
> @@ -653,6 +660,12 @@ int git_atexit(void (*handler)(void))
>  }
>  #define atexit git_atexit
>  
> +static int process_is_async;
> +int in_async(void)
> +{
> +	return process_is_async;
> +}
> +
>  #endif
>  
>  int start_async(struct async *async)
> @@ -712,6 +725,7 @@ int start_async(struct async *async)
>  		if (need_out)
>  			close(fdout[0]);
>  		git_atexit_clear();
> +		process_is_async = 1;
>  		exit(!!async->proc(proc_in, proc_out, async->data));
>  	}
>  
> diff --git a/run-command.h b/run-command.h
> index 5b4425a..629fab7 100644
> --- a/run-command.h
> +++ b/run-command.h
> @@ -118,5 +118,6 @@ struct async {
>  
>  int start_async(struct async *async);
>  int finish_async(struct async *async);
> +int in_async(void);
>  
>  #endif
Jeff King· Sep 1, 2015, 22:17 UTC · re: Junio C Hamano · lore

Re: [PATCH 1/2] run-command: provide in_async query function

On Tue, Sep 01, 2015 at 03:09:56PM -0700, Junio C Hamano wrote:
Show 33 quoted lines
> Jeff King <peff@peff.net> writes:
> 
> > It's not easy for arbitrary code to find out whether it is
> > running in an async process or not. A top-level function
> > which is fed to start_async() can know (you just pass down
> > an argument saying "you are async"). But that function may
> > call other global functions, and we would not want to have
> > to pass the information all the way through the call stack.
> >
> > Nor can we simply set a global variable, as those may be
> > shared between async threads and the main thread (if the
> > platform supports pthreads). We need pthread tricks _or_ a
> > global variable, depending on how start_async is
> > implemented.
> >
> > The callers don't have enough information to do this right,
> > so let's provide a simple query function that does.
> > Fortunately we can reuse the existing infrastructure to make
> > the pthread case simple (and even simplify die_async() by
> > using our new function).
> >
> > Signed-off-by: Jeff King <peff@peff.net>
> > ---
> 
> What is not immediately obvious from the above description is why a
> code may want to care if it is in_async() in the first place.
> 
> If there weren't the die_async() update, the readers might have been
> left utterly baffled (or they can somehow see this is related to
> 2/2) but it is a bit hard to arrange in "git log" as going to child
> is harder.
> 
> The patch looks good.  Thanks.

Yeah, I almost mentioned "...in the next patch we'll need this", but I wasn't sure how to bring that up without going into the complicated reasoning in that patch. I don't know if it's worth adding "we don't have any callers yet, but we will add one in a moment".

-Peff
Jeff King· Sep 1, 2015, 20:24 UTC · re: Jeff King · lore

[PATCH 2/2] pkt-line: show packets in async processes as "sideband"

If you run "GIT_TRACE_PACKET=1 git push", you may get confusing output like (line prefixes omitted for clarity):

   packet:      push< \1000eunpack ok0019ok refs/heads/master0000
   packet:      push< unpack ok
   packet:      push< ok refs/heads/master
   packet:      push< 0000
   packet:      push< 0000

Why do we see the data twice, once apparently wrapped inside another pkt-line, and once unwrapped? Why do we get two flush packets?

The answer is that we start an async process to demux the sideband data. The first entry comes from the sideband process reading the data, and the second from push itself. Likewise, the first flush is inside the demuxed packet, and the second is an actual sideband flush.

We can make this a bit more clear by marking the sideband demuxer explicitly as "sideband" rather than "push". The most elegant way to do this would be to simply call packet_trace_identity() inside the sideband demuxer. But we can't do that reliably, because it relies on a global variable, which might be shared if pthreads are in use.

What we really need is thread-local storage for packet_trace_identity. But the async code does not provide an interface for that, and it would be messy to add it here (we'd have to care about pthreads, initializing our pthread_key_t ahead of time, etc).

So instead, let us just assume that any async process is handling sideband data. That's always true now, and is likely to remain so in the future.

The output looks like:
   packet:  sideband< \1000eunpack ok0019ok refs/heads/master0000
   packet:      push< unpack ok
   packet:      push< ok refs/heads/master
   packet:      push< 0000
   packet:  sideband< 0000
Signed-off-by: Jeff King <peff@peff.net>
---
 pkt-line.c | 8 +++++++-
 1 file changed, 7 insertions(+), 1 deletion(-)
Show changes to pkt-line.c +7 −1
diff --git a/pkt-line.c b/pkt-line.c
index 08a1427..62fdb37 100644
--- a/pkt-line.c
+++ b/pkt-line.c
@@ -1,5 +1,6 @@
 #include "cache.h"
 #include "pkt-line.h"
+#include "run-command.h"
 
 char packet_buffer[LARGE_PACKET_MAX];
 static const char *packet_trace_prefix = "git";
@@ -11,6 +12,11 @@ void packet_trace_identity(const char *prog)
 	packet_trace_prefix = xstrdup(prog);
 }
 
+static const char *get_trace_prefix(void)
+{
+	return in_async() ? "sideband" : packet_trace_prefix;
+}
+
 static int packet_trace_pack(const char *buf, unsigned int len, int sideband)
 {
 	if (!sideband) {
@@ -57,7 +63,7 @@ static void packet_trace(const char *buf, unsigned int len, int write)
 	strbuf_init(&out, len+32);
 
 	strbuf_addf(&out, "packet: %12s%c ",
-		    packet_trace_prefix, write ? '>' : '<');
+		    get_trace_prefix(), write ? '>' : '<');
 
 	/* XXX we should really handle printable utf8 */
 	for (i = 0; i < len; i++) {
-- 
2.5.1.739.g7891f6b
Junio C Hamano· Sep 1, 2015, 22:13 UTC · re: Jeff King · lore

Re: [PATCH 2/2] pkt-line: show packets in async processes as "sideband"

Jeff King <peff@peff.net> writes:
Show 5 quoted lines
> What we really need is thread-local storage for
> packet_trace_identity. But the async code does not provide
> an interface for that, and it would be messy to add it here
> (we'd have to care about pthreads, initializing our
> pthread_key_t ahead of time, etc).
True.
> So instead, let us just assume that any async process is
> handling sideband data. That's always true now, and is
> likely to remain so in the future.

Hmm, does Stefan's thread-pool thing interact with this decision in any way?

Show 46 quoted lines
>
> The output looks like:
>
>    packet:  sideband< \1000eunpack ok0019ok refs/heads/master0000
>    packet:      push< unpack ok
>    packet:      push< ok refs/heads/master
>    packet:      push< 0000
>    packet:  sideband< 0000
>
> Signed-off-by: Jeff King <peff@peff.net>
> ---
>  pkt-line.c | 8 +++++++-
>  1 file changed, 7 insertions(+), 1 deletion(-)
>
> diff --git a/pkt-line.c b/pkt-line.c
> index 08a1427..62fdb37 100644
> --- a/pkt-line.c
> +++ b/pkt-line.c
> @@ -1,5 +1,6 @@
>  #include "cache.h"
>  #include "pkt-line.h"
> +#include "run-command.h"
>  
>  char packet_buffer[LARGE_PACKET_MAX];
>  static const char *packet_trace_prefix = "git";
> @@ -11,6 +12,11 @@ void packet_trace_identity(const char *prog)
>  	packet_trace_prefix = xstrdup(prog);
>  }
>  
> +static const char *get_trace_prefix(void)
> +{
> +	return in_async() ? "sideband" : packet_trace_prefix;
> +}
> +
>  static int packet_trace_pack(const char *buf, unsigned int len, int sideband)
>  {
>  	if (!sideband) {
> @@ -57,7 +63,7 @@ static void packet_trace(const char *buf, unsigned int len, int write)
>  	strbuf_init(&out, len+32);
>  
>  	strbuf_addf(&out, "packet: %12s%c ",
> -		    packet_trace_prefix, write ? '>' : '<');
> +		    get_trace_prefix(), write ? '>' : '<');
>  
>  	/* XXX we should really handle printable utf8 */
>  	for (i = 0; i < len; i++) {
Jeff King· Sep 1, 2015, 22:22 UTC · re: Junio C Hamano · lore

Re: [PATCH 2/2] pkt-line: show packets in async processes as "sideband"

On Tue, Sep 01, 2015 at 03:13:25PM -0700, Junio C Hamano wrote:
Show 6 quoted lines
> > So instead, let us just assume that any async process is
> > handling sideband data. That's always true now, and is
> > likely to remain so in the future.
> 
> Hmm, does Stefan's thread-pool thing interact with this decision in
> any way?
I don't think so. It is true that:
  start_async(...);
  finish_async(...);
  pthread_create(foo);

would incorrectly report in_async() inside the foo function (because we know that async has been kicked off, and we know that we are in a thread that is not the main one).

But I don't think it matters in the current code base, because we tend to use async for I/O tasks like muxing/demuxing, and real threads in CPU-heavy tasks like pack-objects.

Still, I admit it is a little gross, and may be a problem in the future.

An alternate approach would be to have the async system provide a thread-local storage abstraction. With pthreads, we'd build on pthread_setspecific(), and without, it becomes a simple global variable.

That's more work, but a lot less error-prone, and it may come in handy in the future.

-Peff
Stefan Beller· Sep 1, 2015, 22:23 UTC · re: Junio C Hamano · lore

Re: [PATCH 2/2] pkt-line: show packets in async processes as "sideband"

On Tue, Sep 1, 2015 at 3:13 PM, Junio C Hamano <gitster@pobox.com> wrote:
Show 16 quoted lines
> Jeff King <peff@peff.net> writes:
>
>> What we really need is thread-local storage for
>> packet_trace_identity. But the async code does not provide
>> an interface for that, and it would be messy to add it here
>> (we'd have to care about pthreads, initializing our
>> pthread_key_t ahead of time, etc).
>
> True.
>
>> So instead, let us just assume that any async process is
>> handling sideband data. That's always true now, and is
>> likely to remain so in the future.
>
> Hmm, does Stefan's thread-pool thing interact with this decision in
> any way?

I do not plan to actually fetch from inside the thread pool, but each thread is just a proxy for starting a new process doing the fetch and getting the output in order.

That seems to be the least amount of work to me. Very long term we may want to do the fetch directly in a thread pool worker, but then we can also add the thread local storage interface.

Show 46 quoted lines
>>
>> The output looks like:
>>
>>    packet:  sideband< \1000eunpack ok0019ok refs/heads/master0000
>>    packet:      push< unpack ok
>>    packet:      push< ok refs/heads/master
>>    packet:      push< 0000
>>    packet:  sideband< 0000
>>
>> Signed-off-by: Jeff King <peff@peff.net>
>> ---
>>  pkt-line.c | 8 +++++++-
>>  1 file changed, 7 insertions(+), 1 deletion(-)
>>
>> diff --git a/pkt-line.c b/pkt-line.c
>> index 08a1427..62fdb37 100644
>> --- a/pkt-line.c
>> +++ b/pkt-line.c
>> @@ -1,5 +1,6 @@
>>  #include "cache.h"
>>  #include "pkt-line.h"
>> +#include "run-command.h"
>>
>>  char packet_buffer[LARGE_PACKET_MAX];
>>  static const char *packet_trace_prefix = "git";
>> @@ -11,6 +12,11 @@ void packet_trace_identity(const char *prog)
>>       packet_trace_prefix = xstrdup(prog);
>>  }
>>
>> +static const char *get_trace_prefix(void)
>> +{
>> +     return in_async() ? "sideband" : packet_trace_prefix;
>> +}
>> +
>>  static int packet_trace_pack(const char *buf, unsigned int len, int sideband)
>>  {
>>       if (!sideband) {
>> @@ -57,7 +63,7 @@ static void packet_trace(const char *buf, unsigned int len, int write)
>>       strbuf_init(&out, len+32);
>>
>>       strbuf_addf(&out, "packet: %12s%c ",
>> -                 packet_trace_prefix, write ? '>' : '<');
>> +                 get_trace_prefix(), write ? '>' : '<');
>>
>>       /* XXX we should really handle printable utf8 */
>>       for (i = 0; i < len; i++) {
Jeff King· Sep 1, 2015, 22:26 UTC · re: Stefan Beller · lore

Re: [PATCH 2/2] pkt-line: show packets in async processes as "sideband"

On Tue, Sep 01, 2015 at 03:23:06PM -0700, Stefan Beller wrote:
Show 7 quoted lines
> > Hmm, does Stefan's thread-pool thing interact with this decision in
> > any way?
> 
> I do not plan to actually fetch from inside the thread pool, but each thread
> is just a proxy for starting a new process doing the fetch and getting
> the output
> in order.

Ah, right, I think I misunderstood Junio's question. Yes, if we start calling cmd_fetch() from inside the threads, things may get confusing.

I'll see how painful the thread storage approach would be.
-Peff
Stefan Beller· Sep 1, 2015, 22:31 UTC · re: Jeff King · lore

Re: [PATCH 2/2] pkt-line: show packets in async processes as "sideband"

On Tue, Sep 1, 2015 at 3:26 PM, Jeff King <peff@peff.net> wrote:
Show 14 quoted lines
> On Tue, Sep 01, 2015 at 03:23:06PM -0700, Stefan Beller wrote:
>
>> > Hmm, does Stefan's thread-pool thing interact with this decision in
>> > any way?
>>
>> I do not plan to actually fetch from inside the thread pool, but each thread
>> is just a proxy for starting a new process doing the fetch and getting
>> the output
>> in order.
>
> Ah, right, I think I misunderstood Junio's question. Yes, if we start
> calling cmd_fetch() from inside the threads, things may get confusing.
>
> I'll see how painful the thread storage approach would be.
I think that may be part of the thread pool API eventually.

I don't plan on relying on thread local storage, which is why I did not add it there, though I guess it can be added in there quite conveniently.

>
> -Peff
Jeff King· Sep 1, 2015, 22:38 UTC · re: Stefan Beller · lore

Re: [PATCH 2/2] pkt-line: show packets in async processes as "sideband"

On Tue, Sep 01, 2015 at 03:31:41PM -0700, Stefan Beller wrote:
Show 10 quoted lines
> > Ah, right, I think I misunderstood Junio's question. Yes, if we start
> > calling cmd_fetch() from inside the threads, things may get confusing.
> >
> > I'll see how painful the thread storage approach would be.
> 
> I think that may be part of the thread pool API eventually.
> 
> I don't plan on relying on thread local storage, which is why I did
> not add it there,
> though I guess it can be added in there quite conveniently.

I think the task_queue and the async code are two separate things, though. The task_queue, when we do not have threads, falls back to doing things serially in a single process. Changing "thread local" variables there is OK, but tasks need to be aware that they might affect subsequent tasks.

Whereas for async code, we fall back to doing things in a forked sub-process. And there "thread local" really is local to the async process, no cleanup required.

-Peff

← back to recent threads