Re: [PATCH 1/8] trace2: create new combined trace facility

From: Stefan Beller <sbeller@google.com>
Date: Sep 4, 2018, 22:12 UTC
Message-ID: <CAGZ79kbUYDAKi-K2uHpkffPjMxGYtH=QUMhvfq4HTc5+a7-eBA@mail.gmail.com>
In-Reply-To: <82885700379efe6d6a83629cac4d943b99b393bf.1535734192.git.gitgitgadget@gmail.com>

> Create GIT_TR2 trace-key to replace GIT_TRACE, GIT_TR2_PERFORMANCE to
> replace GIT_TRACE_PERFORMANCE, and a new trace-key GIT_TR2_EVENT to
> generate JSON data for telemetry purposes.  Other structured formats
> can easily be added later using this new existing model.

So the idea is to use the GIT_TR2 instead of GIT_TRACE and we get the same output as well as a new form of structured logging here? (Then GIT_TRACE could be retired, and we'd use the new API to add more events, which are also more structured as the API allows for more than just a string printed?)

Show 8 quoted lines

> Define a higher-level event API that selectively writes to all of the
> new GIT_TR2_* targets (depending on event type) without needing to call
> different trace_printf*() or trace_performance_*() routines.
>
> The API defines both fixed-field and printf-style functions.
>
> The trace2 performance tracing includes thread-specific function
> nesting and timings.

So this only adds the new API, and we need to merge the TRACE into the TRACE2 later?

> +++ b/trace2.c
> @@ -0,0 +1,1592 @@

[...]

> +
> +/*****************************************************************
> + * TODO remove this section header
> + *****************************************************************/

Yes, please.

Show 6 quoted lines

> +/*
> + * Compute a "unique" session id (SID) for the current process.  All events
> + * from this process will have this label.  If we were started by another
> + * git instance, use our parent's SID as a prefix and count the number of
> + * nested git processes.  (This lets us track parent/child relationships
> + * even if there is an intermediate shell process.)

How does this work with threading. From this description we can have two threads starting new child processes and they have the same ID (<our id>-2)

> +
> +/*****************************************************************
> + * TODO remove this section header
> + *****************************************************************/

This looks like a reoccurring pattern. Did you have a tool that needs these? Does the tool want to enforce some level of documentation on each function?

Show 6 quoted lines

> +
> +/*
> + * Each thread (including the main thread) has a stack of nested regions.
> + * This is used to indent messages and provide nested perf times.  The
> + * limit here is for simplicity.  Note that the region stack is per-thread
> + * and not per-trace_key.

What are the (nested) regions used for? I would imagine recursive operations, e.g. unpacking trees? Where am I supposed to read up on those?

> + */
> +#define TR2_MAX_REGION_NESTING (100)
> +#define TR2_INDENT (2)
> +#define TR2_INDENT_LENGTH(ctx) (((ctx)->nr_open_regions - 1) * TR2_INDENT)

In the structured part of the logging the indentation would not be needed and we'd rather want to store the nesting level as an int, this is solely for printing locally I'd assume.

> +#define TR2_MAX_THREAD_NAME (24)

This is the max length for a thread name including all the prefixes?

Show 7 quoted lines

> +static void tr2tls_unset_self(void)
> +{
> +       struct tr2tls_thread_ctx * ctx;
> +
> +       ctx = tr2tls_get_self();
> +
> +       pthread_setspecific(tr2tls_key, NULL);

Would we also need to free tr2tls_key ?

Show 10 quoted lines

> +/*****************************************************************
> + * TODO remove this section header
> + *****************************************************************/
> +
> +static void tr2io_write_line(struct trace_key *key, struct strbuf *buf_line)
> +{
> +       strbuf_complete_line(buf_line); /* ensure final NL on buffer */
> +
> +       // TODO we don't really want short-writes to try again when
> +       // TODO we are in append mode...

A different kind of TODO in a // comment?