Re: [PATCH v1 03/25] structured-logging: add structured logging framework

From: Jonathan Nieder <jrnieder@gmail.com>
Date: Aug 21, 2018, 05:05 UTC
Message-ID: <20180821050541.GC219616@aiede.svl.corp.google.com>
In-Reply-To: <20180713165621.52017-4-git@jeffhostetler.com>

Jeff Hostetler wrote:

[...]

Show 9 quoted lines

> --- a/compat/mingw.h
> +++ b/compat/mingw.h
> @@ -144,8 +144,15 @@ static inline int fcntl(int fd, int cmd, ...)
>  	errno = EINVAL;
>  	return -1;
>  }
> +
>  /* bash cannot reliably detect negative return codes as failure */
> +#if defined(STRUCTURED_LOGGING)

Git usually spells this as #ifdef.

Show 5 quoted lines

> +#include "structured-logging.h"
> +#define exit(code) exit(strlog_exit_code((code) & 0xff))
> +#else
>  #define exit(code) exit((code) & 0xff)
> +#endif

This is hard to follow, since it only makes sense in combination with the corresponding code in git-compat-util.h. Can they be defined together? If not, can they have comments to make it easier to know to edit one too when editing the other?

[...]

Show 7 quoted lines

> --- a/git-compat-util.h
> +++ b/git-compat-util.h
> @@ -1239,4 +1239,13 @@ extern void unleak_memory(const void *ptr, size_t len);
>  #define UNLEAK(var) do {} while (0)
>  #endif
>  
> +#include "structured-logging.h"

Is this #include needed? Usually git-compat-util.h only defines C standard library functions or utilities that are used everywhere.

[...]

> --- a/git.c
> +++ b/git.c

[...]

Show 18 quoted lines

> @@ -700,7 +701,7 @@ static int run_argv(int *argcp, const char ***argv)
>  	return done_alias;
>  }
>  
> -int cmd_main(int argc, const char **argv)
> +static int real_cmd_main(int argc, const char **argv)
>  {
>  	const char *cmd;
>  	int done_help = 0;
> @@ -779,3 +780,8 @@ int cmd_main(int argc, const char **argv)
>  
>  	return 1;
>  }
> +
> +int cmd_main(int argc, const char **argv)
> +{
> +	return slog_wrap_main(real_cmd_main, argc, argv);
> +}

Can real_cmd_main get a different name, describing what it does?

[...]

> --- a/structured-logging.c
> +++ b/structured-logging.c
> @@ -1,3 +1,10 @@

[...]

Show 10 quoted lines

> +static uint64_t my__start_time;
> +static uint64_t my__exit_time;
> +static int my__is_config_loaded;
> +static int my__is_enabled;
> +static int my__is_pretty;
> +static int my__signal;
> +static int my__exit_code;
> +static int my__pid;
> +static int my__wrote_start_event;
> +static int my__log_fd = -1;

Please don't use this my__ notation. The inconsistency with the rest of Git makes the code feel out of place and provides an impediment to smooth reading.

[...]

Show 10 quoted lines

> +static void emit_start_event(void)
> +{
> +	struct json_writer jw = JSON_WRITER_INIT;
> +
> +	/* build "cmd_start" event message */
> +	jw_object_begin(&jw, my__is_pretty);
> +	{
> +		jw_object_string(&jw, "event", "cmd_start");
> +		jw_object_intmax(&jw, "clock_us", (intmax_t)my__start_time);
> +		jw_object_intmax(&jw, "pid", (intmax_t)my__pid);

The use of blocks here is unexpected and makes me wonder what kind of macro wizardry is going on. Perhaps this is idiomatic for the json-writer API; if so, can you add an example to json-writer.h to help the next surprised reader?

That said, I think

	json_object_begin(&jw, ...);

	json_object_string(...
	json_object_int(...
	...

	json_object_begin_inline_array(&jw, "argv");
	for (k = 0; k < argv.argc; k++)
		json_object_string(...
	json_object_end(&jw);

	json_object_end(&jw);

is still readable and less unexpected.

[...]

Show 6 quoted lines

> +static void emit_exit_event(void)
> +{
> +	struct json_writer jw = JSON_WRITER_INIT;
> +	uint64_t atexit_time = getnanotime() / 1000;
> +
> +	/* close unterminated forms */

What are unterminated forms?

> +	if (my__errors.json.len)
> +		jw_end(&my__errors);

[...]

Show 8 quoted lines

> +int slog_default_config(const char *key, const char *value)
> +{
> +	const char *sub;
> +
> +	/*
> +	 * git_default_config() calls slog_default_config() with "slog.*"
> +	 * k/v pairs.  git_default_config() MAY or MAY NOT be called when
> +	 * cmd_<command>() calls git_config().

No need to shout.

[...]

Show 8 quoted lines

> +/*
> + * If cmd_<command>() did not cause slog_default_config() to be called
> + * during git_config(), we try to lookup our config settings the first
> + * time we actually need them.
> + *
> + * (We do this rather than using read_early_config() at initialization
> + * because we want any "-c key=value" arguments to be included.)
> + */

Which function is initialization referring to here?

Lazy loading in order to guarantee loading after a different subsystem sounds a bit fragile, so I wonder if we can make the sequencing more explicit.

Stopping here. I still like where this is going, but some aspects of the coding style are making it hard to see the forest for the trees. Perhaps some more details about API in the design doc would help.

Thanks and hope that helps, Jonathan